Reimplement raw logging to avoid Abseil internals

The defined raw logging macros should be compatible with Abseil and
we can remove our version once Abseil releases theirs.

PiperOrigin-RevId: 347354273
Change-Id: I178a89cfd2e19bcd707a06fa9dfd7b767e2b654b
This commit is contained in:
Christian Blichmann 2020-12-14 03:33:29 -08:00 committed by Copybara-Service
parent 8bf410f0bb
commit c3ac45be3e
15 changed files with 320 additions and 109 deletions

View File

@ -23,6 +23,7 @@
#include <syscall.h> #include <syscall.h>
#include <unistd.h> #include <unistd.h>
#include <cinttypes>
#include <climits> #include <climits>
#include <cstddef> #include <cstddef>
#include <cstdint> #include <cstdint>
@ -116,7 +117,7 @@ void Client::SetUpCwd() {
1, 1,
"chdir(%s) failed, falling back to previous cwd or / (with " "chdir(%s) failed, falling back to previous cwd or / (with "
"namespaces). Use Executor::SetCwd() to set a working directory: %s", "namespaces). Use Executor::SetCwd() to set a working directory: %s",
cwd, StrError(errno)); cwd.c_str(), StrError(errno).c_str());
} }
} }
} }
@ -201,8 +202,9 @@ void Client::ApplyPolicyAndBecomeTracee() {
prog.len = static_cast<uint16_t>(policy_.size() / sizeof(sock_filter)); prog.len = static_cast<uint16_t>(policy_.size() / sizeof(sock_filter));
prog.filter = reinterpret_cast<sock_filter*>(&policy_.front()); prog.filter = reinterpret_cast<sock_filter*>(&policy_.front());
SAPI_RAW_VLOG( SAPI_RAW_VLOG(1,
1, "Applying policy in PID %d, sock_fprog.len: %hd entries (%d bytes)", "Applying policy in PID %zd, sock_fprog.len: %" PRId16
" entries (%" PRIuPTR " bytes)",
syscall(__NR_gettid), prog.len, policy_.size()); syscall(__NR_gettid), prog.len, policy_.size());
// Signal executor we are ready to have limits applied on us and be ptraced. // Signal executor we are ready to have limits applied on us and be ptraced.

View File

@ -143,7 +143,7 @@ bool Comms::Listen() {
return false; return false;
} }
SAPI_RAW_VLOG(1, "Listening at: %s", socket_name_); SAPI_RAW_VLOG(1, "Listening at: %s", socket_name_.c_str());
return true; return true;
} }
@ -171,7 +171,7 @@ bool Comms::Accept() {
state_ = State::kConnected; state_ = State::kConnected;
SAPI_RAW_VLOG(1, "Accepted connection at: %s, fd: %d", socket_name_, SAPI_RAW_VLOG(1, "Accepted connection at: %s, fd: %d", socket_name_.c_str(),
connection_fd_); connection_fd_);
return true; return true;
} }
@ -207,7 +207,8 @@ bool Comms::Connect() {
state_ = State::kConnected; state_ = State::kConnected;
SAPI_RAW_VLOG(1, "Connected to: %s, fd: %d", socket_name_, connection_fd_); SAPI_RAW_VLOG(1, "Connected to: %s, fd: %d", socket_name_.c_str(),
connection_fd_);
return true; return true;
} }
@ -230,22 +231,23 @@ void Comms::Terminate() {
bool Comms::SendTLV(uint32_t tag, size_t length, const void* value) { bool Comms::SendTLV(uint32_t tag, size_t length, const void* value) {
if (length > GetMaxMsgSize()) { if (length > GetMaxMsgSize()) {
SAPI_RAW_LOG(ERROR, "Maximum TLV message size exceeded: (%u > %u)", length, SAPI_RAW_LOG(ERROR, "Maximum TLV message size exceeded: (%zu > %zu)",
GetMaxMsgSize()); length, GetMaxMsgSize());
return false; return false;
} }
if (length > kWarnMsgSize) { if (length > kWarnMsgSize) {
static int times_warned = 0; static int times_warned = 0;
if (times_warned < 10) { if (times_warned < 10) {
++times_warned; ++times_warned;
SAPI_RAW_LOG(WARNING, SAPI_RAW_LOG(
"TLV message of size %u detected. Please consider switching " WARNING,
"TLV message of size %zu detected. Please consider switching "
"to Buffer API instead.", "to Buffer API instead.",
length); length);
} }
} }
SAPI_RAW_VLOG(3, "Sending a TLV message, tag: 0x%08x, length: %u", tag, SAPI_RAW_VLOG(3, "Sending a TLV message, tag: 0x%08x, length: %zu", tag,
length); length);
{ {
absl::MutexLock lock(&tlv_send_transmission_mutex_); absl::MutexLock lock(&tlv_send_transmission_mutex_);
@ -364,7 +366,7 @@ bool Comms::RecvFD(int* fd) {
return false; return false;
} }
if (len != sizeof(tlv)) { if (len != sizeof(tlv)) {
SAPI_RAW_LOG(ERROR, "Expected size: %u, got %d", sizeof(tlv), len); SAPI_RAW_LOG(ERROR, "Expected size: %zu, got %zd", sizeof(tlv), len);
return false; return false;
} }
// At this point, we know that op() has been called successfully, therefore // At this point, we know that op() has been called successfully, therefore
@ -453,7 +455,8 @@ bool Comms::SendFD(int fd) {
return false; return false;
} }
if (len != sizeof(tlv)) { if (len != sizeof(tlv)) {
SAPI_RAW_LOG(ERROR, "Expected to send %u bytes, sent %d", sizeof(tlv), len); SAPI_RAW_LOG(ERROR, "Expected to send %zu bytes, sent %zd", sizeof(tlv),
len);
return false; return false;
} }
return true; return true;
@ -467,7 +470,7 @@ bool Comms::RecvProtoBuf(google::protobuf::Message* message) {
SAPI_RAW_PLOG(ERROR, "RecvProtoBuf failed for (%s)", socket_name_); SAPI_RAW_PLOG(ERROR, "RecvProtoBuf failed for (%s)", socket_name_);
} else { } else {
Terminate(); Terminate();
SAPI_RAW_VLOG(2, "Connection terminated (%s)", socket_name_); SAPI_RAW_VLOG(2, "Connection terminated (%s)", socket_name_.c_str());
} }
return false; return false;
} }
@ -536,7 +539,8 @@ bool Comms::Send(const void* data, size_t len) {
return false; return false;
} }
if (s == 0) { if (s == 0) {
SAPI_RAW_LOG(ERROR, "Couldn't write more bytes, wrote: %u, requested: %u", SAPI_RAW_LOG(ERROR,
"Couldn't write more bytes, wrote: %zu, requested: %zu",
total_sent, len); total_sent, len);
return false; return false;
} }
@ -582,8 +586,8 @@ bool Comms::RecvTL(uint32_t* tag, size_t* length) {
return false; return false;
} }
if (*length > GetMaxMsgSize()) { if (*length > GetMaxMsgSize()) {
SAPI_RAW_LOG(ERROR, "Maximum TLV message size exceeded: (%u > %d)", *length, SAPI_RAW_LOG(ERROR, "Maximum TLV message size exceeded: (%zu > %zd)",
GetMaxMsgSize()); *length, GetMaxMsgSize());
return false; return false;
} }
if (*length > kWarnMsgSize) { if (*length > kWarnMsgSize) {
@ -592,7 +596,7 @@ bool Comms::RecvTL(uint32_t* tag, size_t* length) {
++times_warned; ++times_warned;
SAPI_RAW_LOG( SAPI_RAW_LOG(
WARNING, WARNING,
"TLV message of size: (%u detected. Please consider switching to " "TLV message of size: (%zu detected. Please consider switching to "
"Buffer API instead.", "Buffer API instead.",
*length); *length);
} }
@ -632,7 +636,7 @@ bool Comms::RecvTLV(uint32_t* tag, size_t* length, void* buffer,
} }
if (*length > buffer_size) { if (*length > buffer_size) {
SAPI_RAW_LOG(ERROR, "Buffer size too small (0x%x > 0x%x)", *length, SAPI_RAW_LOG(ERROR, "Buffer size too small (0x%zx > 0x%zx)", *length,
buffer_size); buffer_size);
return false; return false;
} }
@ -652,7 +656,7 @@ bool Comms::RecvInt(void* buffer, size_t len, uint32_t tag) {
return false; return false;
} }
if (received_length != len) { if (received_length != len) {
SAPI_RAW_LOG(ERROR, "Expected length: %u, got: %u", len, received_length); SAPI_RAW_LOG(ERROR, "Expected length: %zu, got: %zu", len, received_length);
return false; return false;
} }
return true; return true;

View File

@ -199,7 +199,8 @@ void ForkServer::PrepareExecveArgs(const ForkRequest& request,
} }
SAPI_RAW_VLOG(1, "Will execute args:['%s'], environment:['%s']", SAPI_RAW_VLOG(1, "Will execute args:['%s'], environment:['%s']",
absl::StrJoin(*args, "', '"), absl::StrJoin(*envp, "', '")); absl::StrJoin(*args, "', '").c_str(),
absl::StrJoin(*envp, "', '").c_str());
} }
void ForkServer::LaunchChild(const ForkRequest& request, int execve_fd, void ForkServer::LaunchChild(const ForkRequest& request, int execve_fd,
@ -236,11 +237,11 @@ void ForkServer::LaunchChild(const ForkRequest& request, int execve_fd,
auto caps = cap_init(); auto caps = cap_init();
for (auto cap : request.capabilities()) { for (auto cap : request.capabilities()) {
SAPI_RAW_CHECK(cap_set_flag(caps, CAP_PERMITTED, 1, &cap, CAP_SET) == 0, SAPI_RAW_CHECK(cap_set_flag(caps, CAP_PERMITTED, 1, &cap, CAP_SET) == 0,
"setting capability %d", cap); absl::StrCat("setting capability ", cap).c_str());
SAPI_RAW_CHECK(cap_set_flag(caps, CAP_EFFECTIVE, 1, &cap, CAP_SET) == 0, SAPI_RAW_CHECK(cap_set_flag(caps, CAP_EFFECTIVE, 1, &cap, CAP_SET) == 0,
"setting capability %d", cap); absl::StrCat("setting capability ", cap).c_str());
SAPI_RAW_CHECK(cap_set_flag(caps, CAP_INHERITABLE, 1, &cap, CAP_SET) == 0, SAPI_RAW_CHECK(cap_set_flag(caps, CAP_INHERITABLE, 1, &cap, CAP_SET) == 0,
"setting capability %d", cap); absl::StrCat("setting capability ", cap).c_str());
} }
SAPI_RAW_CHECK(cap_set_proc(caps) == 0, "while dropping capabilities"); SAPI_RAW_CHECK(cap_set_proc(caps) == 0, "while dropping capabilities");
@ -261,7 +262,8 @@ void ForkServer::LaunchChild(const ForkRequest& request, int execve_fd,
} }
// Send sandboxee pid // Send sandboxee pid
auto status = SendPid(signaling_fd); auto status = SendPid(signaling_fd);
SAPI_RAW_CHECK(status.ok(), "sending pid: %s", status.message()); SAPI_RAW_CHECK(status.ok(),
absl::StrCat("sending pid: ", status.message()).c_str());
} }
if (request.mode() == FORKSERVER_FORK_EXECVE_SANDBOX || if (request.mode() == FORKSERVER_FORK_EXECVE_SANDBOX ||
@ -395,9 +397,11 @@ pid_t ForkServer::ServeRequest() {
} }
// Send sandboxee pid // Send sandboxee pid
absl::Status status = SendPid(fd_closer1.get()); absl::Status status = SendPid(fd_closer1.get());
SAPI_RAW_CHECK(status.ok(), "sending pid: %s", status.message()); SAPI_RAW_CHECK(status.ok(),
absl::StrCat("sending pid: ", status.message()).c_str());
} else if (auto pid_or = ReceivePid(fd_closer0.get()); !pid_or.ok()) { } else if (auto pid_or = ReceivePid(fd_closer0.get()); !pid_or.ok()) {
SAPI_RAW_LOG(ERROR, "receiving pid: %s", pid_or.status().message()); SAPI_RAW_LOG(ERROR, "receiving pid: %s",
std::string(pid_or.status().message()).c_str());
} else { } else {
sandboxee_pid = pid_or.value(); sandboxee_pid = pid_or.value();
} }
@ -429,7 +433,7 @@ pid_t ForkServer::ServeRequest() {
// And the actual sandboxee is forked from the init process, so we need to // And the actual sandboxee is forked from the init process, so we need to
// receive the actual PID. // receive the actual PID.
if (auto pid_or = ReceivePid(fd_closer0.get()); !pid_or.ok()) { if (auto pid_or = ReceivePid(fd_closer0.get()); !pid_or.ok()) {
SAPI_RAW_LOG(ERROR, "%s", pid_or.status().message()); SAPI_RAW_LOG(ERROR, "%s", std::string(pid_or.status().message()).c_str());
kill(init_pid, SIGKILL); kill(init_pid, SIGKILL);
init_pid = -1; init_pid = -1;
} else { } else {
@ -445,10 +449,11 @@ pid_t ForkServer::ServeRequest() {
if (user_ns_fd >= 0) { if (user_ns_fd >= 0) {
close(user_ns_fd); close(user_ns_fd);
} }
SAPI_RAW_CHECK(comms_->SendInt32(init_pid), "Failed to send init PID: %d", SAPI_RAW_CHECK(comms_->SendInt32(init_pid),
init_pid); absl::StrCat("Failed to send init PID: ", init_pid).c_str());
SAPI_RAW_CHECK(comms_->SendInt32(sandboxee_pid), SAPI_RAW_CHECK(
"Failed to send sandboxee PID: %d", sandboxee_pid); comms_->SendInt32(sandboxee_pid),
absl::StrCat("Failed to send sandboxee PID: ", sandboxee_pid).c_str());
return sandboxee_pid; return sandboxee_pid;
} }
@ -459,7 +464,7 @@ bool ForkServer::Initialize() {
// kernel version 3.4, so don't panic if it fails. // kernel version 3.4, so don't panic if it fails.
if (prctl(PR_SET_CHILD_SUBREAPER, 1, 0, 0, 0) == -1) { if (prctl(PR_SET_CHILD_SUBREAPER, 1, 0, 0, 0) == -1) {
SAPI_RAW_VLOG(3, "prctl(PR_SET_CHILD_SUBREAPER, 1): %s [%d]", SAPI_RAW_VLOG(3, "prctl(PR_SET_CHILD_SUBREAPER, 1): %s [%d]",
StrError(errno), errno); StrError(errno).c_str(), errno);
} }
// Don't convert terminated child processes into zombies. It's up to the // Don't convert terminated child processes into zombies. It's up to the

View File

@ -37,6 +37,7 @@
#include "absl/strings/string_view.h" #include "absl/strings/string_view.h"
#include "sandboxed_api/embed_file.h" #include "sandboxed_api/embed_file.h"
#include "sandboxed_api/sandbox2/comms.h" #include "sandboxed_api/sandbox2/comms.h"
#include "sandboxed_api/sandbox2/fork_client.h"
#include "sandboxed_api/sandbox2/forkserver_bin_embed.h" #include "sandboxed_api/sandbox2/forkserver_bin_embed.h"
#include "sandboxed_api/sandbox2/util.h" #include "sandboxed_api/sandbox2/util.h"
#include "sandboxed_api/sandbox2/util/fileops.h" #include "sandboxed_api/sandbox2/util/fileops.h"
@ -160,10 +161,11 @@ void GlobalForkClient::EnsureStarted(GlobalForkserverStartMode mode) {
void GlobalForkClient::EnsureStartedLocked(GlobalForkserverStartMode mode) { void GlobalForkClient::EnsureStartedLocked(GlobalForkserverStartMode mode) {
if (!instance_) { if (!instance_) {
SAPI_RAW_CHECK(!getenv(kForkServerDisableEnv), SAPI_RAW_CHECK(
"Start of the Global Fork-Server prevented by the '%s' " !getenv(kForkServerDisableEnv),
"environment variable present", absl::StrCat("Start of the Global Fork-Server prevented by the '",
kForkServerDisableEnv); kForkServerDisableEnv, "' environment variable present")
.c_str());
SAPI_RAW_CHECK( SAPI_RAW_CHECK(
GetForkserverStartMode().contains(mode), GetForkserverStartMode().contains(mode),
"Start of the Global Fork-Server prevented by commandline flag"); "Start of the Global Fork-Server prevented by commandline flag");

View File

@ -153,7 +153,7 @@ namespace {
void LogContainer(const std::vector<std::string>& container) { void LogContainer(const std::vector<std::string>& container) {
for (size_t i = 0; i < container.size(); ++i) { for (size_t i = 0; i < container.size(); ++i) {
SAPI_RAW_LOG(INFO, "[%4d]=%s", i, container[i]); SAPI_RAW_LOG(INFO, "[%4zd]=%s", i, container[i].c_str());
} }
} }

View File

@ -226,7 +226,8 @@ absl::Status Mounts::Insert(absl::string_view path,
if (curtree->has_node()) { if (curtree->has_node()) {
if (IsEquivalentNode(curtree->node(), new_node)) { if (IsEquivalentNode(curtree->node(), new_node)) {
SAPI_RAW_LOG(INFO, "Inserting %s with the same value twice", path); SAPI_RAW_LOG(INFO, "Inserting %s with the same value twice",
std::string(path).c_str());
return absl::OkStatus(); return absl::OkStatus();
} }
return absl::FailedPreconditionError(absl::StrCat( return absl::FailedPreconditionError(absl::StrCat(
@ -291,7 +292,7 @@ namespace {
void LogContainer(const std::vector<std::string>& container) { void LogContainer(const std::vector<std::string>& container) {
for (size_t i = 0; i < container.size(); ++i) { for (size_t i = 0; i < container.size(); ++i) {
SAPI_RAW_LOG(INFO, "[%4d]=%s", i, container[i]); SAPI_RAW_LOG(INFO, "[%4zd]=%s", i, container[i].c_str());
} }
} }
@ -305,11 +306,12 @@ absl::Status Mounts::AddMappingsForBinary(const std::string& path,
const std::string& interpreter = elf.interpreter(); const std::string& interpreter = elf.interpreter();
if (interpreter.empty()) { if (interpreter.empty()) {
SAPI_RAW_VLOG(1, "The file %s is not a dynamic executable", path); SAPI_RAW_VLOG(1, "The file %s is not a dynamic executable", path.c_str());
return absl::OkStatus(); return absl::OkStatus();
} }
SAPI_RAW_VLOG(1, "The file %s is using interpreter %s", path, interpreter); SAPI_RAW_VLOG(1, "The file %s is using interpreter %s", path.c_str(),
interpreter.c_str());
SAPI_RETURN_IF_ERROR(ValidateInterpreter(interpreter)); SAPI_RETURN_IF_ERROR(ValidateInterpreter(interpreter));
std::vector<std::string> search_paths; std::vector<std::string> search_paths;
@ -369,11 +371,11 @@ absl::Status Mounts::AddMappingsForBinary(const std::string& path,
if (SAPI_VLOG_IS_ON(1)) { if (SAPI_VLOG_IS_ON(1)) {
SAPI_RAW_VLOG( SAPI_RAW_VLOG(
1, "Resolving dynamic library dependencies of %s using these dirs:", 1, "Resolving dynamic library dependencies of %s using these dirs:",
path); path.c_str());
LogContainer(full_search_paths); LogContainer(full_search_paths);
} }
if (SAPI_VLOG_IS_ON(2)) { if (SAPI_VLOG_IS_ON(2)) {
SAPI_RAW_VLOG(2, "Direct dependencies of %s to resolve:", path); SAPI_RAW_VLOG(2, "Direct dependencies of %s to resolve:", path.c_str());
LogContainer(imported_libs); LogContainer(imported_libs);
} }
} }
@ -397,14 +399,15 @@ absl::Status Mounts::AddMappingsForBinary(const std::string& path,
} }
std::string resolved_lib = ResolveLibraryPath(lib, full_search_paths); std::string resolved_lib = ResolveLibraryPath(lib, full_search_paths);
if (resolved_lib.empty()) { if (resolved_lib.empty()) {
SAPI_RAW_LOG(ERROR, "Failed to resolve library: %s", lib); SAPI_RAW_LOG(ERROR, "Failed to resolve library: %s", lib.c_str());
continue; continue;
} }
if (imported_libraries.contains(resolved_lib)) { if (imported_libraries.contains(resolved_lib)) {
continue; continue;
} }
SAPI_RAW_VLOG(1, "Resolved library: %s ==> %s", lib, resolved_lib); SAPI_RAW_VLOG(1, "Resolved library: %s => %s", lib.c_str(),
resolved_lib.c_str());
imported_libraries.insert(resolved_lib); imported_libraries.insert(resolved_lib);
if (imported_libraries.size() > kMaxImportedLibraries) { if (imported_libraries.size() > kMaxImportedLibraries) {
@ -427,7 +430,7 @@ absl::Status Mounts::AddMappingsForBinary(const std::string& path,
if (SAPI_VLOG_IS_ON(2)) { if (SAPI_VLOG_IS_ON(2)) {
SAPI_RAW_VLOG(2, SAPI_RAW_VLOG(2,
"Transitive dependencies of %s to resolve (depth = %d): ", "Transitive dependencies of %s to resolve (depth = %d): ",
resolved_lib, depth + 1); resolved_lib.c_str(), depth + 1);
LogContainer(imported_libs); LogContainer(imported_libs);
} }
@ -538,8 +541,9 @@ void MountWithDefaults(const std::string& source, const std::string& target,
if (is_ro) { if (is_ro) {
flags |= MS_RDONLY; flags |= MS_RDONLY;
} }
SAPI_RAW_VLOG(1, R"(mount("%s", "%s", "%s", %d, "%s"))", source, target, SAPI_RAW_VLOG(1, R"(mount("%s", "%s", "%s", %s, "%s"))", source.c_str(),
fs_type, flags, option_str); target.c_str(), fs_type, MountFlagsToString(flags).c_str(),
option_str);
int res = mount(source.c_str(), target.c_str(), fs_type, flags, option_str); int res = mount(source.c_str(), target.c_str(), fs_type, flags, option_str);
if (res == -1) { if (res == -1) {
@ -547,7 +551,8 @@ void MountWithDefaults(const std::string& source, const std::string& target,
// File does not exist (anymore). This is e.g. the case when we're trying // File does not exist (anymore). This is e.g. the case when we're trying
// to gather stack-traces on SAPI crashes. The sandboxee application is a // to gather stack-traces on SAPI crashes. The sandboxee application is a
// memfd file that is not existing anymore. // memfd file that is not existing anymore.
SAPI_RAW_LOG(WARNING, "Could not mount %s: file does not exist", source); SAPI_RAW_LOG(WARNING, "Could not mount %s: file does not exist",
source.c_str());
return; return;
} }
SAPI_RAW_PLOG(FATAL, "mounting %s to %s failed (flags=%s)", source, target, SAPI_RAW_PLOG(FATAL, "mounting %s to %s failed (flags=%s)", source, target,
@ -569,7 +574,7 @@ void MountWithDefaults(const std::string& source, const std::string& target,
if (propagation != 0) { if (propagation != 0) {
res = mount("", target.c_str(), "", propagation, nullptr); res = mount("", target.c_str(), "", propagation, nullptr);
SAPI_RAW_PCHECK(res != -1, "changing %s mount propagation to %s failed", SAPI_RAW_PCHECK(res != -1, "changing %s mount propagation to %s failed",
target, MountFlagsToString(propagation)); target, MountFlagsToString(propagation).c_str());
} }
} }
@ -580,7 +585,7 @@ void CreateMounts(const MountTree& tree, const std::string& path,
if (create_backing_files) { if (create_backing_files) {
switch (tree.node().node_case()) { switch (tree.node().node_case()) {
case MountTree::Node::kFileNode: { case MountTree::Node::kFileNode: {
SAPI_RAW_VLOG(2, "Creating backing file at %s", path); SAPI_RAW_VLOG(2, "Creating backing file at %s", path.c_str());
int fd = open(path.c_str(), O_CREAT | O_EXCL | O_WRONLY, 0600); int fd = open(path.c_str(), O_CREAT | O_EXCL | O_WRONLY, 0600);
SAPI_RAW_PCHECK(fd != -1, ""); SAPI_RAW_PCHECK(fd != -1, "");
SAPI_RAW_PCHECK(close(fd) == 0, ""); SAPI_RAW_PCHECK(close(fd) == 0, "");
@ -590,7 +595,7 @@ void CreateMounts(const MountTree& tree, const std::string& path,
case MountTree::Node::kTmpfsNode: case MountTree::Node::kTmpfsNode:
case MountTree::Node::kRootNode: case MountTree::Node::kRootNode:
case MountTree::Node::NODE_NOT_SET: case MountTree::Node::NODE_NOT_SET:
SAPI_RAW_VLOG(2, "Creating directory at %s", path); SAPI_RAW_VLOG(2, "Creating directory at %s", path.c_str());
SAPI_RAW_PCHECK(mkdir(path.c_str(), 0700) == 0 || errno == EEXIST, ""); SAPI_RAW_PCHECK(mkdir(path.c_str(), 0700) == 0 || errno == EEXIST, "");
break; break;
// Intentionally no default to make sure we handle all the cases. // Intentionally no default to make sure we handle all the cases.

View File

@ -51,9 +51,8 @@ int MountFallbackToReadOnly(const char* source, const char* target,
const void* data) { const void* data) {
int rv = mount(source, target, filesystem, flags, data); int rv = mount(source, target, filesystem, flags, data);
if (rv != 0 && (flags & MS_RDONLY) == 0) { if (rv != 0 && (flags & MS_RDONLY) == 0) {
SAPI_RAW_LOG(WARNING, SAPI_RAW_PLOG(WARNING, "Mounting %s on %s (fs type %s) read-write failed",
"Mounting %s on %s (fs type %s) read-write failed: %s", source, source, target, filesystem);
target, filesystem, StrError(errno));
rv = mount(source, target, filesystem, flags | MS_RDONLY, data); rv = mount(source, target, filesystem, flags | MS_RDONLY, data);
if (rv == 0) { if (rv == 0) {
SAPI_RAW_LOG(INFO, "Mounted %s on %s (fs type %s) as read-only", source, SAPI_RAW_LOG(INFO, "Mounted %s on %s (fs type %s) as read-only", source,
@ -183,7 +182,8 @@ void LogFilesystem(const std::string& dir) {
if (S_ISLNK(st.st_mode)) { if (S_ISLNK(st.st_mode)) {
link = absl::StrCat(" -> ", file_util::fileops::ReadLink(full_path)); link = absl::StrCat(" -> ", file_util::fileops::ReadLink(full_path));
} }
SAPI_RAW_VLOG(2, "%s %s%s", type_and_mode, full_path, link); SAPI_RAW_VLOG(2, "%s %s%s", type_and_mode.c_str(), full_path.c_str(),
link.c_str());
if (S_ISDIR(st.st_mode)) { if (S_ISDIR(st.st_mode)) {
LogFilesystem(full_path); LogFilesystem(full_path);

View File

@ -58,13 +58,13 @@ bool ListNumericalDirectoryEntries(const std::string& directory,
std::string error; std::string error;
if (!file_util::fileops::ListDirectoryEntries(directory, &entries, &error)) { if (!file_util::fileops::ListDirectoryEntries(directory, &entries, &error)) {
SAPI_RAW_LOG(WARNING, "List directory entries for '%s' failed: %s", SAPI_RAW_LOG(WARNING, "List directory entries for '%s' failed: %s",
kProcSelfFd, error); kProcSelfFd, error.c_str());
return false; return false;
} }
for (const auto& entry : entries) { for (const auto& entry : entries) {
int num; int num;
if (!absl::SimpleAtoi(entry, &num)) { if (!absl::SimpleAtoi(entry, &num)) {
SAPI_RAW_LOG(WARNING, "Cannot convert %s to a number", entry); SAPI_RAW_LOG(WARNING, "Cannot convert %s to a number", entry.c_str());
return false; return false;
} }
nums->insert(num); nums->insert(num);
@ -78,19 +78,21 @@ std::string GetProcStatusLine(int pid, const std::string& value) {
std::string procpidstatus; std::string procpidstatus;
auto status = file::GetContents(fname, &procpidstatus, file::Defaults()); auto status = file::GetContents(fname, &procpidstatus, file::Defaults());
if (!status.ok()) { if (!status.ok()) {
SAPI_RAW_LOG(WARNING, "%s", status.message()); SAPI_RAW_LOG(WARNING, "%s", std::string(status.message()).c_str());
return ""; return "";
} }
for (const auto& line : absl::StrSplit(procpidstatus, '\n')) { for (const auto& line : absl::StrSplit(procpidstatus, '\n')) {
std::pair<absl::string_view, absl::string_view> kv = std::pair<std::string, std::string> kv =
absl::StrSplit(line, absl::MaxSplits(':', 1)); absl::StrSplit(line, absl::MaxSplits(':', 1));
SAPI_RAW_VLOG(3, "Key: '%s' Value: '%s'", kv.first, kv.second); SAPI_RAW_VLOG(3, "Key: '%s' Value: '%s'", kv.first.c_str(),
kv.second.c_str());
if (kv.first == value) { if (kv.first == value) {
return std::string(kv.second); return std::move(kv.second);
} }
} }
SAPI_RAW_LOG(ERROR, "No '%s' field found in '%s'", value, fname); SAPI_RAW_LOG(ERROR, "No '%s' field found in '%s'", value.c_str(),
fname.c_str());
return ""; return "";
} }
@ -167,7 +169,8 @@ int GetNumberOfThreads(int pid) {
} }
int threads; int threads;
if (!absl::SimpleAtoi(thread_str, &threads)) { if (!absl::SimpleAtoi(thread_str, &threads)) {
SAPI_RAW_LOG(ERROR, "Couldn't convert '%s' to a number", thread_str); SAPI_RAW_LOG(ERROR, "Couldn't convert '%s' to a number",
thread_str.c_str());
return -1; return -1;
} }
SAPI_RAW_VLOG(1, "Found %d threads in pid: %d", threads, pid); SAPI_RAW_VLOG(1, "Found %d threads in pid: %d", threads, pid);
@ -194,7 +197,7 @@ void WaitForTsan() {
bool SanitizeCurrentProcess(const std::set<int>& fd_exceptions, bool SanitizeCurrentProcess(const std::set<int>& fd_exceptions,
bool close_fds) { bool close_fds) {
SAPI_RAW_VLOG(1, "Sanitizing PID: %d, close_fds: %d", syscall(__NR_getpid), SAPI_RAW_VLOG(1, "Sanitizing PID: %zu, close_fds: %d", syscall(__NR_getpid),
close_fds); close_fds);
// Put process in a separate session (and a new process group). // Put process in a separate session (and a new process group).

View File

@ -153,7 +153,7 @@ std::vector<std::string> RunLibUnwindAndSymbolizer(pid_t pid,
}); });
if (!f) { if (!f) {
// Could not open maps file. // Could not open maps file.
SAPI_RAW_LOG(ERROR, "Could not open %s", path_maps); SAPI_RAW_LOG(ERROR, "Could not open %s", path_maps.c_str());
return {}; return {};
} }
@ -196,8 +196,9 @@ std::vector<std::string> RunLibUnwindAndSymbolizer(pid_t pid,
auto elf = ElfFile::ParseFromFile(entry.path, ElfFile::kLoadSymbols); auto elf = ElfFile::ParseFromFile(entry.path, ElfFile::kLoadSymbols);
if (!elf.ok()) { if (!elf.ok()) {
SAPI_RAW_LOG(WARNING, "Could not load symbols for %s: %s", entry.path, SAPI_RAW_LOG(WARNING, "Could not load symbols for %s: %s",
elf.status().message()); entry.path.c_str(),
std::string(elf.status().message()).c_str());
continue; continue;
} }

View File

@ -300,7 +300,8 @@ absl::StatusOr<std::string> ReadCPathFromPid(pid_t pid, uintptr_t ptr) {
{reinterpret_cast<void*>(ptr + len1), len2}, {reinterpret_cast<void*>(ptr + len1), len2},
}; };
SAPI_RAW_VLOG(4, "ReadCPathFromPid (iovec): len1: %d, len2: %d", len1, len2); SAPI_RAW_VLOG(4, "ReadCPathFromPid (iovec): len1: %zu, len2: %zu", len1,
len2);
ssize_t sz = process_vm_readv(pid, local_iov, ABSL_ARRAYSIZE(local_iov), ssize_t sz = process_vm_readv(pid, local_iov, ABSL_ARRAYSIZE(local_iov),
remote_iov, ABSL_ARRAYSIZE(remote_iov), 0); remote_iov, ABSL_ARRAYSIZE(remote_iov), 0);
if (sz < 0) { if (sz < 0) {

View File

@ -360,7 +360,7 @@ absl::Status ElfParser::ReadSymbolsFromSymtab(const Elf64_Shdr& symtab) {
return absl::InternalError( return absl::InternalError(
absl::StrCat("invalid symtab's strtab reference: ", symtab.sh_link)); absl::StrCat("invalid symtab's strtab reference: ", symtab.sh_link));
} }
SAPI_RAW_VLOG(1, "Symbol table with %d entries found", symbol_entries); SAPI_RAW_VLOG(1, "Symbol table with %zu entries found", symbol_entries);
SAPI_ASSIGN_OR_RETURN(std::string strtab, ReadSectionContents(symtab.sh_link)); SAPI_ASSIGN_OR_RETURN(std::string strtab, ReadSectionContents(symtab.sh_link));
SAPI_ASSIGN_OR_RETURN(std::string symbols, ReadSectionContents(symtab)); SAPI_ASSIGN_OR_RETURN(std::string symbols, ReadSectionContents(symtab));
result_.symbols_.reserve(result_.symbols_.size() + symbol_entries); result_.symbols_.reserve(result_.symbols_.size() + symbol_entries);
@ -418,7 +418,7 @@ absl::Status ElfParser::ReadImportedLibrariesFromDynamic(
return absl::InternalError( return absl::InternalError(
absl::StrCat("invalid dynamic's strtab reference: ", dynamic.sh_link)); absl::StrCat("invalid dynamic's strtab reference: ", dynamic.sh_link));
} }
SAPI_RAW_VLOG(1, "Dynamic section with %d entries found", entries); SAPI_RAW_VLOG(1, "Dynamic section with %zu entries found", entries);
// strtab may be shared with symbols and therefore huge // strtab may be shared with symbols and therefore huge
const auto& strtab_section = section_headers_.at(dynamic.sh_link); const auto& strtab_section = section_headers_.at(dynamic.sh_link);
if (strtab_section.sh_offset > file_size_) { if (strtab_section.sh_offset > file_size_) {

View File

@ -29,7 +29,7 @@ std::string GetDataDependencyFilePath(absl::string_view relative_path) {
static Runfiles* runfiles = []() { static Runfiles* runfiles = []() {
std::string error; std::string error;
auto* runfiles = Runfiles::Create(gflags::GetArgv0(), &error); auto* runfiles = Runfiles::Create(gflags::GetArgv0(), &error);
SAPI_RAW_CHECK(runfiles != nullptr, "%s", error); SAPI_RAW_CHECK(runfiles != nullptr, error.c_str());
// Setup environment for child processes. // Setup environment for child processes.
for (const auto& entry : runfiles->EnvVars()) { for (const auto& entry : runfiles->EnvVars()) {

View File

@ -116,6 +116,9 @@ cc_library(
copts = sapi_platform_copts(), copts = sapi_platform_copts(),
deps = [ deps = [
"//sandboxed_api/sandbox2/util:strerror", "//sandboxed_api/sandbox2/util:strerror",
"@com_google_absl//absl/base:config",
"@com_google_absl//absl/base:core_headers",
"@com_google_absl//absl/base:log_severity",
"@com_google_absl//absl/strings", "@com_google_absl//absl/strings",
"@com_google_absl//absl/strings:str_format", "@com_google_absl//absl/strings:str_format",
], ],

View File

@ -14,14 +14,113 @@
#include "sandboxed_api/util/raw_logging.h" #include "sandboxed_api/util/raw_logging.h"
#include <sys/syscall.h>
#include <unistd.h>
#include <cstdarg>
#include <cstddef>
#include <cstdio>
#include <cstdlib> #include <cstdlib>
#include <cstring>
#include <limits> #include <limits>
#include "absl/base/attributes.h"
#include "absl/base/config.h"
#include "absl/base/log_severity.h"
#include "absl/strings/numbers.h" #include "absl/strings/numbers.h"
#include "absl/strings/str_cat.h" #include "absl/strings/str_cat.h"
#include "absl/strings/str_format.h"
namespace sapi { static const char kTruncated[] = " ... (message truncated)\n";
namespace internal {
// sprintf the format to the buffer, adjusting *buf and *size to reflect the
// consumed bytes, and return whether the message fit without truncation. If
// truncation occurred, if possible leave room in the buffer for the message
// kTruncated[].
inline static bool VADoRawLog(char** buf, int* size, const char* format,
va_list ap) ABSL_PRINTF_ATTRIBUTE(3, 0);
inline static bool VADoRawLog(char** buf, int* size, const char* format,
va_list ap) {
int n = vsnprintf(*buf, *size, format, ap);
bool result = true;
if (n < 0 || n > *size) {
result = false;
if (static_cast<size_t>(*size) > sizeof(kTruncated)) {
n = *size - sizeof(kTruncated); // room for truncation message
} else {
n = 0; // no room for truncation message
}
}
*size -= n;
*buf += n;
return result;
}
static constexpr int kLogBufSize = 3000;
namespace {
// CAVEAT: vsnprintf called from *DoRawLog below has some (exotic) code paths
// that invoke malloc() and getenv() that might acquire some locks.
// Helper for RawLog below.
// *DoRawLog writes to *buf of *size and move them past the written portion.
// It returns true iff there was no overflow or error.
bool DoRawLog(char** buf, int* size, const char* format, ...)
ABSL_PRINTF_ATTRIBUTE(3, 4);
bool DoRawLog(char** buf, int* size, const char* format, ...) {
va_list ap;
va_start(ap, format);
int n = vsnprintf(*buf, *size, format, ap);
va_end(ap);
if (n < 0 || n > *size) return false;
*size -= n;
*buf += n;
return true;
}
void RawLogVA(absl::LogSeverity severity, const char* file, int line,
const char* format, va_list ap) ABSL_PRINTF_ATTRIBUTE(4, 0);
void RawLogVA(absl::LogSeverity severity, const char* file, int line,
const char* format, va_list ap) {
char buffer[kLogBufSize];
char* buf = buffer;
int size = sizeof(buffer);
DoRawLog(&buf, &size, "[%s : %d] RAW: ", file, line);
bool no_chop = VADoRawLog(&buf, &size, format, ap);
if (no_chop) {
DoRawLog(&buf, &size, "\n");
} else {
DoRawLog(&buf, &size, "%s", kTruncated);
}
sapi::raw_logging_internal::SafeWriteToStderr(buffer, strlen(buffer));
// Abort the process after logging a FATAL message, even if the output itself
// was suppressed.
if (severity == absl::LogSeverity::kFatal) {
abort();
}
}
} // namespace
namespace sapi::raw_logging_internal {
void RawLog(absl::LogSeverity severity, const char* file, int line,
const char* format, ...) ABSL_PRINTF_ATTRIBUTE(4, 5);
void RawLog(absl::LogSeverity severity, const char* file, int line,
const char* format, ...) {
va_list ap;
va_start(ap, format);
RawLogVA(severity, file, line, format, ap);
va_end(ap);
}
void SafeWriteToStderr(const char* s, size_t len) {
syscall(SYS_write, STDERR_FILENO, s, len);
}
bool VLogIsOn(int verbose_level) { bool VLogIsOn(int verbose_level) {
static int external_verbose_level = [] { static int external_verbose_level = [] {
@ -30,7 +129,7 @@ bool VLogIsOn(int verbose_level) {
if (!env_var) { if (!env_var) {
return external_verbose_level; return external_verbose_level;
} }
ABSL_RAW_CHECK(absl::SimpleAtoi(env_var, &external_verbose_level) && SAPI_RAW_CHECK(absl::SimpleAtoi(env_var, &external_verbose_level) &&
external_verbose_level >= 0, external_verbose_level >= 0,
"SAPI_VLOG_LEVEL needs to be an integer >= 0"); "SAPI_VLOG_LEVEL needs to be an integer >= 0");
return external_verbose_level; return external_verbose_level;
@ -38,5 +137,4 @@ bool VLogIsOn(int verbose_level) {
return verbose_level >= external_verbose_level; return verbose_level >= external_verbose_level;
} }
} // namespace internal } // namespace sapi::raw_logging_internal
} // namespace sapi

View File

@ -12,55 +12,142 @@
// See the License for the specific language governing permissions and // See the License for the specific language governing permissions and
// limitations under the License. // limitations under the License.
// SAPI raw logging. Forked from Abseil's version.
#ifndef SANDBOXED_API_UTIL_RAW_LOGGING_H_ #ifndef SANDBOXED_API_UTIL_RAW_LOGGING_H_
#define SANDBOXED_API_UTIL_RAW_LOGGING_H_ #define SANDBOXED_API_UTIL_RAW_LOGGING_H_
#include <string>
#include <utility>
#include "sandboxed_api/util/raw_logging.h" #include "sandboxed_api/util/raw_logging.h"
#include "absl/base/attributes.h"
#include "absl/base/config.h"
#include "absl/base/log_severity.h"
#include "absl/base/macros.h"
#include "absl/base/optimization.h"
#include "absl/base/port.h"
#include "absl/strings/str_cat.h" #include "absl/strings/str_cat.h"
#include "absl/strings/str_format.h" #include "absl/strings/str_format.h"
#include "sandboxed_api/sandbox2/util/strerror.h" #include "sandboxed_api/sandbox2/util/strerror.h"
namespace sapi { // `SAPI_INTERNAL_UNREACHABLE` is an unreachable statement. A program which
namespace internal { // reaches one has undefined behavior, and the compiler may optimize
// accordingly.
#if defined(__GNUC__) || ABSL_HAVE_BUILTIN(__builtin_unreachable)
#define SAPI_INTERNAL_UNREACHABLE __builtin_unreachable()
#elif defined(_MSC_VER)
#define SAPI_INTERNAL_UNREACHABLE __assume(0)
#else
#define SAPI_INTERNAL_UNREACHABLE
#endif
bool VLogIsOn(int verbose_level); #ifdef ABSL_RAW_LOG
#define SAPI_RAW_LOG ABSL_RAW_LOG
#else
// This is similar to LOG(severity) << format..., but
// * it is to be used ONLY by low-level modules that can't use normal LOG()
// * it is designed to be a low-level logger that does not allocate any
// memory and does not need any locks, hence:
// * it logs straight and ONLY to STDERR w/o buffering
// * it uses an explicit printf-format and arguments list
// * it will silently chop off really long message strings
// Usage example:
// SAPI_RAW_LOG(ERROR, "Failed foo with %i: %s", status, error);
// This will print an almost standard log line like this to stderr only:
// E0821 211317 file.cc:123] RAW: Failed foo with 22: bad_file
} // namespace internal #define SAPI_RAW_LOG(severity, ...) \
} // namespace sapi do { \
constexpr const char* absl_raw_logging_internal_basename = \
::sapi::raw_logging_internal::Basename(__FILE__, \
sizeof(__FILE__) - 1); \
::sapi::raw_logging_internal::RawLog(SAPI_RAW_LOGGING_INTERNAL_##severity, \
absl_raw_logging_internal_basename, \
__LINE__, __VA_ARGS__); \
} while (0)
#endif
#ifdef ABSL_RAW_CHECK
#define SAPI_RAW_CHECK ABSL_RAW_CHECK
#else
// Similar to CHECK(condition) << message, but for low-level modules:
// we use only SAPI_RAW_LOG that does not allocate memory.
// We do not want to provide args list here to encourage this usage:
// if (!cond) SAPI_RAW_LOG(FATAL, "foo ...", hard_to_compute_args);
// so that the args are not computed when not needed.
#define SAPI_RAW_CHECK(condition, message) \
do { \
if (ABSL_PREDICT_FALSE(!(condition))) { \
SAPI_RAW_LOG(FATAL, "Check %s failed: %s", #condition, message); \
} \
} while (0)
#endif
#define SAPI_RAW_LOGGING_INTERNAL_INFO ::absl::LogSeverity::kInfo
#define SAPI_RAW_LOGGING_INTERNAL_WARNING ::absl::LogSeverity::kWarning
#define SAPI_RAW_LOGGING_INTERNAL_ERROR ::absl::LogSeverity::kError
#define SAPI_RAW_LOGGING_INTERNAL_FATAL ::absl::LogSeverity::kFatal
// Returns whether SAPI verbose logging is enabled, as determined by the // Returns whether SAPI verbose logging is enabled, as determined by the
// SAPI_VLOG_LEVEL environment variable. // SAPI_VLOG_LEVEL environment variable.
#define SAPI_VLOG_IS_ON(verbose_level) ::sapi::internal::VLogIsOn(verbose_level) #define SAPI_VLOG_IS_ON(verbose_level) \
::sapi::raw_logging_internal::VLogIsOn(verbose_level)
// This is similar to LOG(severity) << format..., but intended for low-level
// modules that cannot use regular logging (i.e. in static initializers). It
// also uses printf-style formatting using absl::StrFormat for type-safety.
#define SAPI_RAW_LOG(severity, format, ...) \
ABSL_INTERNAL_LOG(severity, absl::StrFormat((format), ##__VA_ARGS__))
// Like SAPI_RAW_LOG(), but also logs the current value of errno and its // Like SAPI_RAW_LOG(), but also logs the current value of errno and its
// corresponding error message. // corresponding error message.
#define SAPI_RAW_PLOG(severity, format, ...) \ #define SAPI_RAW_PLOG(severity, format, ...) \
ABSL_INTERNAL_LOG( \ do { \
severity, absl::StrCat(absl::StrFormat((format), ##__VA_ARGS__), ": ", \ const auto message = absl::StrFormat((format), ##__VA_ARGS__); \
::sandbox2::StrError(errno), " [", errno, "]")) SAPI_RAW_LOG(severity, "%s: %s [%d]", message.c_str(), \
::sandbox2::StrError(errno).c_str(), errno); \
} while (0)
// If verbose logging is enabled, uses SAPI_RAW_LOG() to log. // If verbose logging is enabled, uses SAPI_RAW_LOG() to log.
#define SAPI_RAW_VLOG(verbose_level, format, ...) \ #define SAPI_RAW_VLOG(verbose_level, format, ...) \
if (sapi::internal::VLogIsOn(verbose_level)) { \ if (sapi::raw_logging_internal::VLogIsOn(verbose_level)) { \
SAPI_RAW_LOG(INFO, (format), ##__VA_ARGS__); \ SAPI_RAW_LOG(INFO, (format), ##__VA_ARGS__); \
} }
// Like regular CHECK(), but uses raw logging and printf-style formatting.
#define SAPI_RAW_CHECK(condition, format, ...) \
ABSL_INTERNAL_CHECK((condition), absl::StrFormat((format), ##__VA_ARGS__))
// Like SAPI_RAW_CHECK(), but also logs errno and a message (similar to // Like SAPI_RAW_CHECK(), but also logs errno and a message (similar to
// SAPI_RAW_PLOG()). // SAPI_RAW_PLOG()).
#define SAPI_RAW_PCHECK(condition, format, ...) \ #define SAPI_RAW_PCHECK(condition, format, ...) \
ABSL_INTERNAL_CHECK( \ do { \
(condition), \ const auto message = absl::StrFormat((format), ##__VA_ARGS__); \
absl::StrCat(absl::StrFormat((format), ##__VA_ARGS__), ": ", \ if (ABSL_PREDICT_FALSE(!(condition))) { \
::sandbox2::StrError(errno), " [", errno, "]")) SAPI_RAW_LOG(FATAL, "Check %s failed: %s: %s [%d]", #condition, \
message.c_str(), ::sandbox2::StrError(errno).c_str(), \
errno); \
} \
} while (0)
namespace sapi::raw_logging_internal {
// Helper function to implement ABSL_RAW_LOG
// Logs format... at "severity" level, reporting it
// as called from file:line.
// This does not allocate memory or acquire locks.
void RawLog(absl::LogSeverity severity, const char* file, int line,
const char* format, ...) ABSL_PRINTF_ATTRIBUTE(4, 5);
// Writes the provided buffer directly to stderr, in a safe, low-level manner.
//
// In POSIX this means calling write(), which is async-signal safe and does
// not malloc. If the platform supports the SYS_write syscall, we invoke that
// directly to side-step any libc interception.
void SafeWriteToStderr(const char* s, size_t len);
// compile-time function to get the "base" filename, that is, the part of
// a filename after the last "/" or "\" path separator. The search starts at
// the end of the string; the second parameter is the length of the string.
constexpr const char* Basename(const char* fname, int offset) {
return offset == 0 || fname[offset - 1] == '/' || fname[offset - 1] == '\\'
? fname + offset
: Basename(fname, offset - 1);
}
bool VLogIsOn(int verbose_level);
} // namespace sapi::raw_logging_internal
#endif // SANDBOXED_API_UTIL_RAW_LOGGING_H_ #endif // SANDBOXED_API_UTIL_RAW_LOGGING_H_