[logging] Don't write severity when using syslog
When using syslog, the severity is already included in the
metadata so no need to also write it in the log message.
Bug: 40982
Change-Id: I54988a6bfc95db45a2710301e1be2f0b624fa056
Reviewed-on: https://fuchsia-review.googlesource.com/c/fuchsia/+/379054
Commit-Queue: Saman Sami <samans@google.com>
Testability-Review: Adam Perry <adamperry@google.com>
Reviewed-by: Adam Perry <adamperry@google.com>
Reviewed-by: George Kulakowski <kulakowski@google.com>
diff --git a/src/lib/fxl/logging.cc b/src/lib/fxl/logging.cc
index 5a83fea..2aa0ec3 100644
--- a/src/lib/fxl/logging.cc
+++ b/src/lib/fxl/logging.cc
@@ -23,6 +23,7 @@
namespace fxl {
namespace {
+#ifndef __Fuchsia__
const char* const kLogSeverityNames[LOG_NUM_SEVERITIES] = {"INFO", "WARNING", "ERROR", "FATAL"};
const char* GetNameForLogSeverity(LogSeverity severity) {
@@ -30,6 +31,7 @@
return kLogSeverityNames[severity];
return "UNKNOWN";
}
+#endif
const char* StripDots(const char* path) {
while (strncmp(path, "../", 3) == 0)
@@ -62,12 +64,16 @@
#endif
{
stream_ << "[";
+ // With syslog the severity is included in the metadata so no need to add it
+ // to the log message itself.
+#ifndef __Fuchsia__
if (severity >= LOG_INFO)
stream_ << GetNameForLogSeverity(severity);
else
stream_ << "VERBOSE" << -severity;
- stream_ << ":" << (severity > LOG_INFO ? StripDots(file_) : StripPath(file_)) << "(" << line_
- << ")] ";
+ stream_ << ":";
+#endif
+ stream_ << (severity > LOG_INFO ? StripDots(file_) : StripPath(file_)) << "(" << line_ << ")] ";
if (condition)
stream_ << "Check failed: " << condition << ". ";
diff --git a/src/lib/fxl/logging_unittest.cc b/src/lib/fxl/logging_unittest.cc
index 317b54d..c5afbc7 100644
--- a/src/lib/fxl/logging_unittest.cc
+++ b/src/lib/fxl/logging_unittest.cc
@@ -23,32 +23,26 @@
namespace {
#ifdef __Fuchsia__
-bool ends_with(const char* str, const char* suffix) {
- if (strlen(str) < strlen(suffix)) {
- return false;
- }
- size_t l = strlen(suffix);
- str += strlen(str) - l;
- return strcmp(str, suffix) == 0;
-}
-void output_compare_helper_ptr(zx::socket* local, fx_log_severity_t severity, const char* msg,
- const char** tags, int num_tags) {
+struct LogPacket {
+ fx_log_metadata_t metadata;
+ std::vector<std::string> tags;
+ std::string message;
+};
+
+LogPacket ReadPacket(const zx::socket& local) {
+ LogPacket result;
fx_log_packet_t packet;
- ASSERT_EQ(ZX_OK, local->read(0, &packet, sizeof(packet), nullptr));
- EXPECT_EQ(severity, packet.metadata.severity);
+ local.read(0, &packet, sizeof(packet), nullptr);
+ result.metadata = packet.metadata;
int pos = 0;
- for (int i = 0; i < num_tags; i++) {
- const char* tag = tags[i];
- auto tag_len = static_cast<int8_t>(strlen(tag));
- ASSERT_EQ(tag_len, packet.data[pos]);
- pos++;
- ASSERT_STREQ(tag, packet.data + pos);
+ while (packet.data[pos]) {
+ int tag_len = packet.data[pos++];
+ result.tags.emplace_back(packet.data + pos, tag_len);
pos += tag_len;
}
- ASSERT_EQ(0, packet.data[pos]);
- pos++;
- EXPECT_TRUE(ends_with(packet.data + pos, msg)) << (packet.data + pos);
+ result.message.append(packet.data + pos + 1);
+ return result;
}
#endif
@@ -88,11 +82,20 @@
std::string log;
ASSERT_TRUE(files::ReadFileToString(new_settings.log_file, &log));
+#ifdef __Fuchsia__
+ EXPECT_THAT(log, testing::HasSubstr("ERROR: [src/lib/fxl/logging_unittest.cc(" +
+ std::to_string(error_line) + ")] something at error"));
+
+ EXPECT_THAT(log, testing::HasSubstr("INFO: [logging_unittest.cc(" + std::to_string(info_line) +
+ ")] and some other at info level"));
+#else
EXPECT_THAT(log, testing::HasSubstr("[ERROR:src/lib/fxl/logging_unittest.cc(" +
std::to_string(error_line) + ")] something at error"));
EXPECT_THAT(log, testing::HasSubstr("[INFO:logging_unittest.cc(" + std::to_string(info_line) +
")] and some other at info level"));
+
+#endif
}
TEST_F(LoggingFixture, DVLogNoMinLevel) {
@@ -152,17 +155,28 @@
// Initialize syslog with a socket.
zx::socket local, remote;
EXPECT_EQ(ZX_OK, zx::socket::create(ZX_SOCKET_DATAGRAM, &local, &remote));
+ const char* tags[] = {"tags1", "tag2"};
fx_logger_config_t config = {.min_severity = FX_LOG_INFO,
.console_fd = -1,
.log_service_channel = remote.release(),
- .tags = NULL,
- .num_tags = 0};
- ASSERT_EQ(ZX_OK, fx_log_init_with_config(&config));
+ .tags = tags,
+ .num_tags = 2};
+ ASSERT_EQ(ZX_OK, fx_log_reconfigure(&config));
- // Write a message using FXL_LOG an verify that it's forwarded to syslog.
- const char* msg = "test message";
+ // Write a message using FXL_LOG and verify that it's forwarded to syslog.
+ std::string msg = "test message";
FXL_LOG(ERROR) << msg;
- output_compare_helper_ptr(&local, FX_LOG_ERROR, msg, nullptr, 0);
+ LogPacket packet = ReadPacket(local);
+ EXPECT_EQ(2u, packet.tags.size());
+ EXPECT_EQ(tags[0], packet.tags[0]);
+ EXPECT_EQ(tags[1], packet.tags[1]);
+
+ // |msg| should appear at the end of the log.
+ EXPECT_EQ(packet.message.rfind(msg), packet.message.size() - msg.size());
+
+ // The error message should not contain the severity since it's already
+ // included in the metadata.
+ EXPECT_EQ(packet.message.find("ERROR"), std::string::npos);
// Cleanup. Make sure syslog switches back to using stderr.
fx_logger_activate_fallback(fx_log_get_logger(), -1);
diff --git a/src/sys/sysmgr/integration_tests/service_startup_test.cc b/src/sys/sysmgr/integration_tests/service_startup_test.cc
index cc70836..125298e 100644
--- a/src/sys/sysmgr/integration_tests/service_startup_test.cc
+++ b/src/sys/sysmgr/integration_tests/service_startup_test.cc
@@ -150,7 +150,7 @@
"test_sysmgr_service.cc\\([0-9]{1,4}\\): Received ping.",
});
VerifyLogs(log_ptr, {"appmgr"},
- {"\\[INFO:log_connector_impl.cc\\([0-9]{1,4}\\)\\] Successfully set up syslog"});
+ {"\\[log_connector_impl.cc\\([0-9]{1,4}\\)\\] Successfully set up syslog"});
}
} // namespace
