aos: add dynamic logging on an opt-in basis
Applications including this can have vlog changed with:
aos_send /aos aos.logging.DynamicLogCommand '{"name": "app", "vlog_level": 1}'
Change-Id: Id387cdb501ad84ed3e266a2077ea93478b480afa
Signed-off-by: James Kuszmaul <james.kuszmaul@bluerivertech.com>
diff --git a/aos/events/BUILD b/aos/events/BUILD
index e53be2f..1a8d644 100644
--- a/aos/events/BUILD
+++ b/aos/events/BUILD
@@ -146,6 +146,7 @@
src = "aos.json",
flatbuffers = [
":event_loop_fbs",
+ "//aos/logging:dynamic_log_command_fbs",
"//aos/logging:log_message_fbs",
"//aos/starter:starter_fbs",
"//aos/starter:starter_rpc_fbs",
diff --git a/aos/events/aos.json b/aos/events/aos.json
index 875c27e..9780f90 100644
--- a/aos/events/aos.json
+++ b/aos/events/aos.json
@@ -10,6 +10,12 @@
},
{
"name": "/aos",
+ "type": "aos.logging.DynamicLogCommand",
+ "frequency": 10,
+ "num_senders": 1
+ },
+ {
+ "name": "/aos",
"type": "aos.logging.LogMessageFbs",
"frequency": 250,
"num_senders": 20,
diff --git a/aos/logging/BUILD b/aos/logging/BUILD
index 10d41a3..fe8db3a 100644
--- a/aos/logging/BUILD
+++ b/aos/logging/BUILD
@@ -102,3 +102,38 @@
target = ":log_message_fbs_reflection_out",
visibility = ["//visibility:public"],
)
+
+flatbuffer_cc_library(
+ name = "dynamic_log_command_fbs",
+ srcs = [
+ "dynamic_log_command.fbs",
+ ],
+ gen_reflections = 1,
+ visibility = ["//visibility:public"],
+)
+
+cc_library(
+ name = "dynamic_logging",
+ srcs = ["dynamic_logging.cc"],
+ hdrs = ["dynamic_logging.h"],
+ visibility = ["//visibility:public"],
+ deps = [
+ ":dynamic_log_command_fbs",
+ "//aos/events:shm_event_loop",
+ "@com_github_google_glog//:glog",
+ ],
+)
+
+cc_test(
+ name = "dynamic_logging_test",
+ srcs = ["dynamic_logging_test.cc"],
+ data = [
+ "//aos/events:pingpong_config",
+ ],
+ deps = [
+ ":dynamic_logging",
+ "//aos/events:simulated_event_loop",
+ "//aos/testing:googletest",
+ "//aos/testing:path",
+ ],
+)
diff --git a/aos/logging/dynamic_log_command.fbs b/aos/logging/dynamic_log_command.fbs
new file mode 100644
index 0000000..a2db85e
--- /dev/null
+++ b/aos/logging/dynamic_log_command.fbs
@@ -0,0 +1,11 @@
+namespace aos.logging;
+
+table DynamicLogCommand {
+ // Application name
+ name:string (id: 0);
+
+ // vlog level to set
+ vlog_level:int (id: 1);
+}
+
+root_type DynamicLogCommand;
diff --git a/aos/logging/dynamic_logging.cc b/aos/logging/dynamic_logging.cc
new file mode 100644
index 0000000..d28fba2
--- /dev/null
+++ b/aos/logging/dynamic_logging.cc
@@ -0,0 +1,34 @@
+#include "aos/logging/dynamic_logging.h"
+#include "glog/logging.h"
+
+namespace aos {
+namespace logging {
+
+DynamicLogging::DynamicLogging(aos::EventLoop *event_loop)
+ : application_name_(event_loop->name()) {
+ if (event_loop->GetChannel<DynamicLogCommand>("/aos") == nullptr) {
+ LOG(WARNING) << "Disabling dynamic logger because the DynamicLogCommand "
+ "channel is not configured.";
+ } else {
+ event_loop->MakeWatcher("/aos", [this](const DynamicLogCommand &cmd) {
+ HandleDynamicLogCommand(cmd);
+ });
+ }
+}
+
+void DynamicLogging::HandleDynamicLogCommand(const DynamicLogCommand &command) {
+ // For now we expect someone to do an aos_send at the command line, thecommand
+ // may be malformed.
+ if (!command.has_name() || !command.has_vlog_level()) return;
+
+ if (command.name()->string_view() != application_name_) {
+ return;
+ }
+ if (command.vlog_level() < 0) {
+ return;
+ }
+ FLAGS_v = command.vlog_level();
+}
+
+} // namespace logging
+} // namespace aos
diff --git a/aos/logging/dynamic_logging.h b/aos/logging/dynamic_logging.h
new file mode 100644
index 0000000..9fd8fd0
--- /dev/null
+++ b/aos/logging/dynamic_logging.h
@@ -0,0 +1,26 @@
+#include <string>
+#include "aos/events/event_loop.h"
+
+#include "aos/logging/dynamic_log_command_generated.h"
+#include "glog/logging.h"
+
+// The purpose of this class is to listen for /aos aos.logging.DynamicLogCommand
+// and make changes to the log level of the current application based on that
+// message. Currently the only supported command is changing the global vlog
+// level.
+namespace aos {
+namespace logging {
+
+class DynamicLogging {
+ public:
+ DynamicLogging(aos::EventLoop *event_loop);
+ ~DynamicLogging() {}
+
+ private:
+ void HandleDynamicLogCommand(const DynamicLogCommand &command);
+ std::string application_name_;
+ DISALLOW_COPY_AND_ASSIGN(DynamicLogging);
+};
+
+} // namespace logging
+} // namespace aos
diff --git a/aos/logging/dynamic_logging_test.cc b/aos/logging/dynamic_logging_test.cc
new file mode 100644
index 0000000..216193c
--- /dev/null
+++ b/aos/logging/dynamic_logging_test.cc
@@ -0,0 +1,93 @@
+#include <sys/stat.h>
+
+#include "aos/events/event_loop.h"
+#include "aos/events/simulated_event_loop.h"
+#include "aos/logging/dynamic_logging.h"
+#include "aos/testing/path.h"
+#include "glog/logging.h"
+#include "gtest/gtest.h"
+
+using aos::testing::ArtifactPath;
+
+namespace aos {
+namespace logging {
+namespace testing {
+
+namespace chrono = std::chrono;
+
+class DynamicLoggingTest : public ::testing::Test {
+ public:
+ DynamicLoggingTest()
+ : config_(aos::configuration::ReadConfig(
+ ArtifactPath("aos/events/pingpong_config.json"))),
+ event_loop_factory_(&config_.message()),
+ event_loop_send_(event_loop_factory_.MakeEventLoop("send")),
+ event_loop_main_(event_loop_factory_.MakeEventLoop("main")) {}
+
+ aos::FlatbufferDetachedBuffer<aos::Configuration> config_;
+ SimulatedEventLoopFactory event_loop_factory_;
+
+ std::unique_ptr<EventLoop> event_loop_send_;
+ std::unique_ptr<EventLoop> event_loop_main_;
+};
+
+TEST_F(DynamicLoggingTest, TestVLog) {
+ aos::Sender<DynamicLogCommand> dynamic_log_command_sender =
+ event_loop_send_->MakeSender<DynamicLogCommand>("/aos");
+
+ // Set VLOG level to 1 at t=50us and then back to 0 at t=150us.
+ int log_level = 1;
+ aos::TimerHandler *timer_handler = event_loop_send_->AddTimer(
+ [this, &dynamic_log_command_sender, &log_level, &timer_handler]() {
+ aos::Sender<DynamicLogCommand>::Builder message =
+ dynamic_log_command_sender.MakeBuilder();
+ const auto name_str = message.fbb()->CreateString("main");
+
+ DynamicLogCommand::Builder builder =
+ message.MakeBuilder<DynamicLogCommand>();
+ builder.add_name(name_str);
+ builder.add_vlog_level(log_level);
+ CHECK_EQ(message.Send(builder.Finish()), RawSender::Error::kOk);
+ --log_level;
+ if (log_level >= 0) {
+ timer_handler->Setup(event_loop_send_->monotonic_now() +
+ chrono::microseconds(100));
+ }
+ });
+ timer_handler->Setup(event_loop_send_->monotonic_now() +
+ chrono::microseconds(50));
+
+ // VLOG(1) at t=0us, t=100us, t=200us
+ aos::TimerHandler *vlog_timer_handler =
+ event_loop_main_->AddTimer([]() { VLOG(1) << "VLOG 1"; });
+ vlog_timer_handler->Setup(event_loop_main_->monotonic_now(),
+ chrono::microseconds(100));
+
+ DynamicLogging dynamic_logging(event_loop_main_.get());
+
+ {
+ // Validate no log message in first 50us.
+ ::testing::internal::CaptureStderr();
+ event_loop_factory_.RunFor(chrono::microseconds(50));
+ std::string output = ::testing::internal::GetCapturedStderr();
+ EXPECT_EQ(output.find("VLOG 1"), std::string::npos);
+ }
+ {
+ // Validate 1 log message between 50us to 150us
+ ::testing::internal::CaptureStderr();
+ event_loop_factory_.RunFor(chrono::microseconds(100));
+ std::string output = ::testing::internal::GetCapturedStderr();
+ EXPECT_NE(output.find("VLOG 1"), std::string::npos);
+ }
+ {
+ // Validate no log message between 150us to 250us
+ ::testing::internal::CaptureStderr();
+ event_loop_factory_.RunFor(chrono::microseconds(100));
+ std::string output = ::testing::internal::GetCapturedStderr();
+ EXPECT_EQ(output.find("VLOG 1"), std::string::npos);
+ }
+}
+
+} // namespace testing
+} // namespace logging
+} // namespace aos