Skip to content

Commit

Permalink
Improve C++ logging for JNI code.
Browse files Browse the repository at this point in the history
Gets rid of custom logging code that JNI was using and standardizes on `src/main/cpp/util/logging.h`.

JNI sets up a logger when the library is loaded.

PiperOrigin-RevId: 420161386
  • Loading branch information
dmaclach authored and copybara-github committed Jan 6, 2022
1 parent 8ef29dd commit ec05613
Show file tree
Hide file tree
Showing 15 changed files with 83 additions and 165 deletions.
3 changes: 3 additions & 0 deletions src/main/cpp/util/BUILD
Original file line number Diff line number Diff line change
Expand Up @@ -96,6 +96,9 @@ cc_library(
name = "port",
srcs = ["port.cc"],
hdrs = ["port.h"],
visibility = [
"//src/main/native:__pkg__",
],
)

cc_library(
Expand Down
3 changes: 2 additions & 1 deletion src/main/native/BUILD
Original file line number Diff line number Diff line change
Expand Up @@ -76,8 +76,9 @@ cc_binary(
visibility = ["//src/main/java/com/google/devtools/build/lib/jni:__pkg__"],
deps = [
":latin1_jni_path",
"//src/main/cpp/util",
"//src/main/cpp/util:logging",
"//src/main/cpp/util:md5",
"//src/main/cpp/util:port",
],
)

Expand Down
5 changes: 0 additions & 5 deletions src/main/native/darwin/file_jni.cc
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,6 @@

#include <string>

#include "src/main/native/macros.h"
#include "src/main/native/unix_jni.h"

namespace blaze_jni {
Expand Down Expand Up @@ -86,8 +85,6 @@ int StatSeconds(const portable_stat_struct &statbuf, StatTimes t) {
return statbuf.st_ctime;
case STAT_MTIME:
return statbuf.st_mtime;
default:
CHECK(false);
}
}

Expand All @@ -99,8 +96,6 @@ int StatNanoSeconds(const portable_stat_struct &statbuf, StatTimes t) {
return statbuf.st_ctimespec.tv_nsec;
case STAT_MTIME:
return statbuf.st_mtimespec.tv_nsec;
default:
CHECK(false);
}
}

Expand Down
17 changes: 7 additions & 10 deletions src/main/native/darwin/sleep_prevention_jni.cc
Original file line number Diff line number Diff line change
Expand Up @@ -18,9 +18,8 @@
// absl::Mutex but we cannot yet because Bazel doesn't depend on absl.
#include <mutex> // NOLINT

#include "src/main/native/darwin/util.h"
#include "src/main/cpp/util/logging.h"
#include "src/main/native/unix_jni.h"
#include "src/main/native/macros.h"

namespace blaze_jni {

Expand All @@ -35,30 +34,28 @@ static IOPMAssertionID g_sleep_state_assertion = kIOPMNullAssertionID;

int portable_push_disable_sleep() {
std::lock_guard<std::mutex> lock(g_sleep_state_mutex);
CHECK_GE(g_sleep_state_stack, 0);
BAZEL_CHECK_GE(g_sleep_state_stack, 0);
if (g_sleep_state_stack == 0) {
CHECK_EQ(g_sleep_state_assertion, kIOPMNullAssertionID);
BAZEL_CHECK_EQ(g_sleep_state_assertion, kIOPMNullAssertionID);
CFStringRef reasonForActivity = CFSTR("build.bazel");
IOReturn success = IOPMAssertionCreateWithName(
kIOPMAssertionTypeNoIdleSleep, kIOPMAssertionLevelOn, reasonForActivity,
&g_sleep_state_assertion);
CHECK_EQ(success, kIOReturnSuccess);
log_if_possible("sleep assertion created");
BAZEL_CHECK_EQ(success, kIOReturnSuccess);
}
g_sleep_state_stack += 1;
return 0;
}

int portable_pop_disable_sleep() {
std::lock_guard<std::mutex> lock(g_sleep_state_mutex);
CHECK_GT(g_sleep_state_stack, 0);
BAZEL_CHECK_GT(g_sleep_state_stack, 0);
g_sleep_state_stack -= 1;
if (g_sleep_state_stack == 0) {
CHECK_NEQ(g_sleep_state_assertion, kIOPMNullAssertionID);
BAZEL_CHECK_NE(g_sleep_state_assertion, kIOPMNullAssertionID);
IOReturn success = IOPMAssertionRelease(g_sleep_state_assertion);
CHECK_EQ(success, kIOReturnSuccess);
BAZEL_CHECK_EQ(success, kIOReturnSuccess);
g_sleep_state_assertion = kIOPMNullAssertionID;
log_if_possible("sleep assertion released");
}
return 0;
}
Expand Down
15 changes: 7 additions & 8 deletions src/main/native/darwin/system_disk_space_monitor_jni.cc
Original file line number Diff line number Diff line change
Expand Up @@ -15,8 +15,8 @@
#include <notify.h>
#include <notify_keys.h>

#include "src/main/cpp/util/logging.h"
#include "src/main/native/darwin/util.h"
#include "src/main/native/macros.h"
#include "src/main/native/unix_jni.h"

// Not defined by Apple headers, but definitely sent out with macOS 12.
Expand All @@ -32,30 +32,29 @@ void portable_start_disk_space_monitoring() {
dispatch_once(&once_token, ^{
dispatch_queue_t queue = bazel::darwin::JniDispatchQueue();
notify_handler_t lowHandler = (^(int token) {
log_if_possible("disk space low anomaly");
BAZEL_LOG(USER) << "disk space low anomaly";
disk_space_callback(DiskSpaceLevelLow);
});
notify_handler_t veryLowHandler = (^(int token) {
log_if_possible("disk space very low anomaly");
BAZEL_LOG(USER) << "disk space very low anomaly";
disk_space_callback(DiskSpaceLevelVeryLow);
});
int notifyToken;
int status = notify_register_dispatch(kNotifyVFSLowDiskSpace,
&notifyToken,
queue, lowHandler);
CHECK(status == NOTIFY_STATUS_OK);
BAZEL_CHECK_EQ(status, NOTIFY_STATUS_OK);
status = notify_register_dispatch(kNotifyVFSVeryLowDiskSpace,
&notifyToken,
queue, veryLowHandler);
CHECK(status == NOTIFY_STATUS_OK);
BAZEL_CHECK_EQ(status, NOTIFY_STATUS_OK);
// These are registered solely so we can test the system from end-to-end.
status = notify_register_dispatch(
"com.google.bazel.test.diskspace.low", &notifyToken, queue, lowHandler);
CHECK(status == NOTIFY_STATUS_OK);
BAZEL_CHECK_EQ(status, NOTIFY_STATUS_OK);
status = notify_register_dispatch("com.google.bazel.test.diskspace.verylow",
&notifyToken, queue, veryLowHandler);
CHECK(status == NOTIFY_STATUS_OK);
log_if_possible("Disk space monitoring registered");
BAZEL_CHECK_EQ(status, NOTIFY_STATUS_OK);
});
}

Expand Down
22 changes: 8 additions & 14 deletions src/main/native/darwin/system_load_advisory_monitor_jni.cc
Original file line number Diff line number Diff line change
Expand Up @@ -15,18 +15,15 @@
#include <IOKit/pwr_mgt/IOPMLib.h>
#include <notify.h>

#include "src/main/cpp/util/logging.h"
#include "src/main/native/darwin/util.h"
#include "src/main/native/macros.h"
#include "src/main/native/unix_jni.h"

namespace blaze_jni {

static int gSystemLoadAdvisoryNotifyToken = 0;

void portable_start_system_load_advisory_monitoring() {
// To test use:
// /usr/bin/log stream -level debug \
// --predicate '(subsystem == "build.bazel")'
// We install a test notification as well that can be used for testing.
static dispatch_once_t once_token;
dispatch_once(&once_token, ^{
Expand All @@ -38,46 +35,43 @@ void portable_start_system_load_advisory_monitoring() {
int status = notify_register_dispatch(kIOSystemLoadAdvisoryNotifyName,
&gSystemLoadAdvisoryNotifyToken,
queue, handler);
CHECK(status == NOTIFY_STATUS_OK);
BAZEL_CHECK_EQ(status, NOTIFY_STATUS_OK);

// This is registered solely so we can test the system from end-to-end.
// Using the Apple notification requires admin access.
int testToken;
status = notify_register_dispatch(
"com.google.bazel.test.SystemLoadAdvisory", &testToken, queue, handler);
CHECK(status == NOTIFY_STATUS_OK);
log_if_possible("system load advisory monitoring registered");
BAZEL_CHECK_EQ(status, NOTIFY_STATUS_OK);
});
}

int portable_system_load_advisory() {
uint64_t state;
uint32_t status = notify_get_state(gSystemLoadAdvisoryNotifyToken, &state);
if (status != NOTIFY_STATUS_OK) {
log_if_possible("error: notify_get_state failed (%d)", status);
return -1;
BAZEL_LOG(FATAL) << "notify_get_state failed:" << status;
}
IOSystemLoadAdvisoryLevel advisoryLevel = (IOSystemLoadAdvisoryLevel)state;
int load = -1;
switch (advisoryLevel) {
case kIOSystemLoadAdvisoryLevelGreat:
log_if_possible("system load advisory great (0) anomaly");
BAZEL_LOG(USER) << "system load advisory great (0) anomaly";
load = 0;
break;

case kIOSystemLoadAdvisoryLevelOK:
log_if_possible("system load advisory ok (25) anomaly");
BAZEL_LOG(USER) << "system load advisory ok (25) anomaly";
load = 25;
break;

case kIOSystemLoadAdvisoryLevelBad:
log_if_possible("system load advisory bad (75) anomaly");
BAZEL_LOG(USER) << "system load advisory bad (75) anomaly";
load = 75;
break;
}
if (load == -1) {
log_if_possible("error: unknown system load advisory level: %d",
(int)advisoryLevel);
BAZEL_LOG(FATAL) << "unknown system load advisory level: " << advisoryLevel;
}

return load;
Expand Down
23 changes: 10 additions & 13 deletions src/main/native/darwin/system_memory_pressure_jni.cc
Original file line number Diff line number Diff line change
Expand Up @@ -14,16 +14,14 @@

#include <notify.h>

#include "src/main/cpp/util/logging.h"
#include "src/main/native/darwin/util.h"
#include "src/main/native/macros.h"
#include "src/main/native/unix_jni.h"

namespace blaze_jni {

void portable_start_memory_pressure_monitoring() {
// To test use:
// /usr/bin/log stream -level debug \
// --predicate '(subsystem == "build.bazel")'
// sudo memory_pressure -S -l warn
// sudo memory_pressure -S -l critical
// or use the test notifications that we register.
Expand All @@ -33,19 +31,19 @@ void portable_start_memory_pressure_monitoring() {
dispatch_source_t source = dispatch_source_create(
DISPATCH_SOURCE_TYPE_MEMORYPRESSURE, 0,
DISPATCH_MEMORYPRESSURE_WARN | DISPATCH_MEMORYPRESSURE_CRITICAL, queue);
CHECK(source != nullptr);
BAZEL_CHECK_NE(source, nullptr);
dispatch_source_set_event_handler(source, ^{
dispatch_source_memorypressure_flags_t pressureLevel =
dispatch_source_get_data(source);
if (pressureLevel == DISPATCH_MEMORYPRESSURE_WARN) {
log_if_possible("memory pressure warning anomaly");
BAZEL_LOG(USER) << "memory pressure warning anomaly";
memory_pressure_callback(MemoryPressureLevelWarning);
} else if (pressureLevel == DISPATCH_MEMORYPRESSURE_CRITICAL) {
log_if_possible("memory pressure critical anomaly");
BAZEL_LOG(USER) << "memory pressure critical anomaly";
memory_pressure_callback(MemoryPressureLevelCritical);
} else {
log_if_possible("error: unknown memory pressure critical level: %d",
(int)pressureLevel);
BAZEL_LOG(FATAL) << "unknown memory pressure critical level: "
<< pressureLevel;
}
});
dispatch_resume(source);
Expand All @@ -55,18 +53,17 @@ void portable_start_memory_pressure_monitoring() {
int32_t status = notify_register_dispatch(
"com.google.bazel.test.memorypressurelevel.warning", &testToken, queue,
^(int state) {
log_if_possible("memory pressure test warning anomaly");
BAZEL_LOG(USER) << "memory pressure test warning anomaly";
memory_pressure_callback(MemoryPressureLevelWarning);
});
CHECK(status == NOTIFY_STATUS_OK);
BAZEL_CHECK_EQ(status, NOTIFY_STATUS_OK);
status = notify_register_dispatch(
"com.google.bazel.test.memorypressurelevel.critical", &testToken, queue,
^(int state) {
log_if_possible("memory pressure test critical anomaly");
BAZEL_LOG(USER) << "memory pressure test critical anomaly";
memory_pressure_callback(MemoryPressureLevelCritical);
});
CHECK(status == NOTIFY_STATUS_OK);
log_if_possible("memory pressure monitoring registered");
BAZEL_CHECK_EQ(status, NOTIFY_STATUS_OK);
});
}

Expand Down
21 changes: 9 additions & 12 deletions src/main/native/darwin/system_suspension_monitor_jni.cc
Original file line number Diff line number Diff line change
Expand Up @@ -16,8 +16,8 @@
#include <IOKit/pwr_mgt/IOPMLib.h>
#include <notify.h>

#include "src/main/cpp/util/logging.h"
#include "src/main/native/darwin/util.h"
#include "src/main/native/macros.h"
#include "src/main/native/unix_jni.h"

namespace blaze_jni {
Expand All @@ -37,7 +37,7 @@ static void SleepCallBack(void *refcon, io_service_t service,
break;

case kIOMessageSystemWillSleep:
log_if_possible("suspend anomaly due to kIOMessageSystemWillSleep");
BAZEL_LOG(USER) << "suspend anomaly due to kIOMessageSystemWillSleep";
suspend_callback(SuspensionReasonSleep);
// This needs to be acknowledged to allow sleep.
IOAllowPowerChange(state->connect_port, (intptr_t)message_argument);
Expand All @@ -57,7 +57,7 @@ static void SleepCallBack(void *refcon, io_service_t service,
// wasn't. I haven't come up with an smart way of avoiding this issue, but
// I don't think we really care. Over reporting "suspensions" is better
// than under reporting them.
log_if_possible("suspend anomaly due to kIOMessageSystemHasPoweredOn");
BAZEL_LOG(USER) << "suspend anomaly due to kIOMessageSystemHasPoweredOn";
suspend_callback(SuspensionReasonWake);
break;

Expand All @@ -83,11 +83,9 @@ void portable_start_suspend_monitoring() {
// Register to receive system sleep notifications.
// Testing needs to be done manually. Use the logging to verify
// that sleeps are being caught here.
// `/usr/bin/log \
// stream -level debug --predicate '(subsystem == "build.bazel")'`
suspend_state.connect_port = IORegisterForSystemPower(
&suspend_state, &notifyPortRef, SleepCallBack, &notifierObject);
CHECK(suspend_state.connect_port != MACH_PORT_NULL);
BAZEL_CHECK_NE(suspend_state.connect_port, MACH_PORT_NULL);
IONotificationPortSetDispatchQueue(notifyPortRef, queue);

// Register to deal with SIGCONT.
Expand All @@ -98,24 +96,23 @@ void portable_start_suspend_monitoring() {
// having this functionality gives us some ability to unit test suspension
// counts.
sig_t signal_val = signal(SIGCONT, SIG_IGN);
CHECK(signal_val != SIG_ERR);
BAZEL_CHECK_NE(signal_val, SIG_ERR);
dispatch_source_t signal_source =
dispatch_source_create(DISPATCH_SOURCE_TYPE_SIGNAL, SIGCONT, 0, queue);
CHECK(signal_source != nullptr);
BAZEL_CHECK_NE(signal_source, nullptr);
dispatch_source_set_event_handler(signal_source, ^{
log_if_possible("suspend anomaly due to SIGCONT");
BAZEL_LOG(USER) << "suspend anomaly due to SIGCONT";
suspend_callback(SuspensionReasonSIGCONT);
});
dispatch_resume(signal_source);
signal_source =
dispatch_source_create(DISPATCH_SOURCE_TYPE_SIGNAL, SIGTSTP, 0, queue);
CHECK(signal_source != nullptr);
BAZEL_CHECK_NE(signal_source, nullptr);
dispatch_source_set_event_handler(signal_source, ^{
log_if_possible("suspend anomaly due to SIGTSTP");
BAZEL_LOG(USER) << "suspend anomaly due to SIGTSTP";
suspend_callback(SuspensionReasonSIGTSTP);
});
dispatch_resume(signal_source);
log_if_possible("suspend monitoring registered");
});
}

Expand Down
Loading

0 comments on commit ec05613

Please sign in to comment.