[Audit Logging] Stdout logger implementation

src/core/lib/security/authorization/stdout_logger.cc

@@ -21,7 +21,6 @@
 #include <memory>
 #include <string>
 
-#include "absl/status/status.h"
 #include "absl/status/statusor.h"
 #include "absl/strings/str_format.h"
 #include "absl/strings/string_view.h"
@@ -35,17 +34,22 @@
 namespace grpc_core {
 namespace experimental {
 
+namespace {
+
 constexpr absl::string_view kName = "stdout_logger";
 constexpr char kLogFormat[] =
-    "{\"grpc_audit_log\":{\"timestamp\":%d,\"rpc_method\":\"%s\",\"principal\":"
-    "\"%s\",\"policy_name\":\"%s\",\"matched_rule\":\"%s\",\"authorized\":%s}}"
-    "\n";
+    "{\"grpc_audit_log\":{\"timestamp\":\"%s\",\"rpc_method\":\"%s\","
+    "\"principal\":\"%s\",\"policy_name\":\"%s\",\"matched_rule\":\"%s\","
+    "\"authorized\":%s}}\n";
+
+}  // namespace
 
 void StdoutAuditLogger::Log(const AuditContext& context) {
-  absl::FPrintF(stdout, kLogFormat, absl::ToUnixSeconds(absl::Now()),
-                context.rpc_method(), context.principal(),
-                context.policy_name(), context.matched_rule(),
-                context.authorized() ? "true" : "false");
+  absl::FPrintF(
+      stdout, kLogFormat,
+      absl::FormatTime(absl::RFC3339_sec, absl::Now(), absl::LocalTimeZone()),
+      context.rpc_method(), context.principal(), context.policy_name(),
+      context.matched_rule(), context.authorized() ? "true" : "false");
 }
 
 absl::string_view StdoutAuditLoggerFactory::Config::name() const {
@@ -57,10 +61,7 @@ std::string StdoutAuditLoggerFactory::Config::ToString() const { return "{}"; }
 absl::string_view StdoutAuditLoggerFactory::name() const { return kName; }
 
 absl::StatusOr<std::unique_ptr<AuditLoggerFactory::Config>>
-StdoutAuditLoggerFactory::ParseAuditLoggerConfig(const Json& json) {
-  if (json.type() != Json::Type::kObject) {
-    return absl::InvalidArgumentError("config is not a json object");
-  }
+StdoutAuditLoggerFactory::ParseAuditLoggerConfig(const Json&) {
   return std::make_unique<StdoutAuditLoggerFactory::Config>();
 }
 

test/core/security/grpc_audit_logging_test.cc

@@ -34,6 +34,7 @@
 
 #include "src/core/lib/json/json.h"
 #include "src/core/lib/json/json_reader.h"
+#include "src/core/lib/json/json_writer.h"
 #include "src/core/lib/security/authorization/audit_logging.h"
 #include "test/core/util/test_config.h"
 #include "test/core/util/tls_utils.h"
@@ -117,15 +118,6 @@ TEST(StdoutLoggerTest, LoggerFactoryExistenceChecks) {
   EXPECT_TRUE(AuditLoggerRegistry::FactoryExists("stdout_logger"));
 }
 
-TEST(StdoutLoggerTest, BadLoggerConfig) {
-  auto invalid_value = Json::FromBool(false);
-  auto result =
-      AuditLoggerRegistry::ParseConfig("stdout_logger", invalid_value);
-  ASSERT_EQ(result.status().code(), absl::StatusCode::kInvalidArgument);
-  ASSERT_EQ(result.status().message(), "config is not a json object")
-      << result.status();
-}
-
 TEST(StdoutLoggerTest, StdoutLoggerCreationAndLogInvocation) {
   auto result =
       AuditLoggerRegistry::ParseConfig("stdout_logger", Json::FromObject({}));
@@ -134,36 +126,38 @@ TEST(StdoutLoggerTest, StdoutLoggerCreationAndLogInvocation) {
       AuditLoggerRegistry::CreateAuditLogger(std::move(result.value()));
   AuditContext context("method", "spiffe", "policy", "rule", true);
   ::testing::internal::CaptureStdout();
+  int64_t time_before_log = absl::ToUnixSeconds(absl::Now());
   logger->Log(context);
+  int64_t time_after_log = absl::ToUnixSeconds(absl::Now());
   auto log_or = JsonParse(::testing::internal::GetCapturedStdout());
   ASSERT_TRUE(log_or.ok());
-  ASSERT_EQ(log_or.value().type(), Json::Type::kObject);
-  auto it = log_or.value().object().find("grpc_audit_log");
-  ASSERT_NE(it, log_or.value().object().end());
+  ASSERT_EQ(log_or->type(), Json::Type::kObject);
+  auto it = log_or->object().find("grpc_audit_log");
+  ASSERT_NE(it, log_or->object().end());
   ASSERT_EQ(it->second.type(), Json::Type::kObject);
-  auto object = it->second.object();
-  // Check if the recorded timestamp is close to now.
-  absl::Time t1 = absl::Now();
+  auto& object = it->second.object();
   ASSERT_NE(object.find("timestamp"), object.end());
-  EXPECT_EQ(object.find("timestamp")->second.type(), Json::Type::kNumber);
-  uint64_t ts;
-  ASSERT_TRUE(absl::SimpleAtoi(object.find("timestamp")->second.string(), &ts));
-  absl::Time t2 = absl::FromUnixSeconds(ts);
-  EXPECT_TRUE(t1 - t2 < absl::Seconds(10));
+  EXPECT_EQ(object.find("timestamp")->second.type(), Json::Type::kString);
+  absl::Time log_time;
+  ASSERT_TRUE(absl::ParseTime(absl::RFC3339_sec,
+                              object.find("timestamp")->second.string(),
+                              &log_time, nullptr));
+  int64_t time_at_log = absl::ToUnixSeconds(log_time);
+  // Check if the recorded timestamp is in between the recorded interval with
+  // the precision of one second.
+  EXPECT_TRUE(time_at_log >= time_before_log && time_at_log <= time_after_log);
   // Check exact values of everything else.
-  std::map<std::string, std::string> fields = {{"rpc_method", "method"},
-                                               {"principal", "spiffe"},
-                                               {"policy_name", "policy"},
-                                               {"matched_rule", "rule"}};
-  for (const auto& p : fields) {
-    auto it = object.find(p.first);
+  std::vector<std::string> fields = {"rpc_method", "principal", "policy_name",
+                                     "matched_rule", "authorized"};
+  Json::Object json_object;
+  for (const auto& field : fields) {
+    auto it = object.find(field);
     ASSERT_NE(it, object.end());
-    ASSERT_EQ(it->second.type(), Json::Type::kString);
-    EXPECT_EQ(it->second.string(), p.second);
+    json_object.emplace(field, it->second);
   }
-  ASSERT_NE(object.find("authorized"), object.end());
-  ASSERT_EQ(object.find("authorized")->second.type(), Json::Type::kBoolean);
-  EXPECT_EQ(object.find("authorized")->second.boolean(), true);
+  EXPECT_EQ(JsonDump(Json::FromObject(json_object)),
+            "{\"authorized\":true,\"matched_rule\":\"rule\",\"policy_name\":"
+            "\"policy\",\"principal\":\"spiffe\",\"rpc_method\":\"method\"}");
 }
 
 }  // namespace testing