track_event_parser: Support priority for log messages

Reported-at: google#507
Change-Id: I624f4afdd83d3bc6bbef72726c0acbc65cc703f4

Author: ddiproietto

protos/perfetto/trace/perfetto_trace.proto

@@ -9099,6 +9099,17 @@ message LogMessage {
   optional uint64 source_location_iid = 1;
   // interned LogMessageBody.
   optional uint64 body_iid = 2;
+  enum Priority {
+    PRIO_UNSPECIFIED = 0;
+    PRIO_UNUSED = 1;
+    PRIO_VERBOSE = 2;
+    PRIO_DEBUG = 3;
+    PRIO_INFO = 4;
+    PRIO_WARN = 5;
+    PRIO_ERROR = 6;
+    PRIO_FATAL = 7;
+  }
+  optional Priority prio = 3;
 }
 
 // --------------------
@@ -9109,6 +9120,7 @@ message LogMessageBody {
   optional uint64 iid = 1;
   optional string body = 2;
 }
+
 // End of protos/perfetto/trace/track_event/log_message.proto
 
 // Begin of protos/perfetto/trace/track_event/source_location.proto

protos/perfetto/trace/track_event/log_message.proto

@@ -23,6 +23,17 @@ message LogMessage {
   optional uint64 source_location_iid = 1;
   // interned LogMessageBody.
   optional uint64 body_iid = 2;
+  enum Priority {
+    PRIO_UNSPECIFIED = 0;
+    PRIO_UNUSED = 1;
+    PRIO_VERBOSE = 2;
+    PRIO_DEBUG = 3;
+    PRIO_INFO = 4;
+    PRIO_WARN = 5;
+    PRIO_ERROR = 6;
+    PRIO_FATAL = 7;
+  }
+  optional Priority prio = 3;
 }
 
 // --------------------
@@ -32,4 +43,4 @@ message LogMessage {
 message LogMessageBody {
   optional uint64 iid = 1;
   optional string body = 2;
-}
+}

src/trace_processor/importers/proto/track_event_parser.cc

@@ -230,6 +230,29 @@ std::optional<base::Status> MaybeParseSourceLocation(
   return base::OkStatus();
 }
 
+protos::pbzero::AndroidLogPriority ToAndroidLogPriority(
+    protos::pbzero::LogMessage::Priority prio) {
+  switch (prio) {
+    case protos::pbzero::LogMessage::Priority::PRIO_UNSPECIFIED:
+      return protos::pbzero::AndroidLogPriority::PRIO_UNSPECIFIED;
+    case protos::pbzero::LogMessage::Priority::PRIO_UNUSED:
+      return protos::pbzero::AndroidLogPriority::PRIO_UNUSED;
+    case protos::pbzero::LogMessage::Priority::PRIO_VERBOSE:
+      return protos::pbzero::AndroidLogPriority::PRIO_VERBOSE;
+    case protos::pbzero::LogMessage::Priority::PRIO_DEBUG:
+      return protos::pbzero::AndroidLogPriority::PRIO_DEBUG;
+    case protos::pbzero::LogMessage::Priority::PRIO_INFO:
+      return protos::pbzero::AndroidLogPriority::PRIO_INFO;
+    case protos::pbzero::LogMessage::Priority::PRIO_WARN:
+      return protos::pbzero::AndroidLogPriority::PRIO_WARN;
+    case protos::pbzero::LogMessage::Priority::PRIO_ERROR:
+      return protos::pbzero::AndroidLogPriority::PRIO_ERROR;
+    case protos::pbzero::LogMessage::Priority::PRIO_FATAL:
+      return protos::pbzero::AndroidLogPriority::PRIO_FATAL;
+  }
+  return protos::pbzero::AndroidLogPriority::PRIO_UNSPECIFIED;
+}
+
 }  // namespace
 
 class TrackEventParser::EventImporter {
@@ -1331,11 +1354,17 @@ class TrackEventParser::EventImporter {
     // The track event log message doesn't specify any priority. UI never
     // displays priorities < 2 (VERBOSE in android). Let's make all the track
     // event logs show up as INFO.
-    constexpr uint32_t kPriority =
-        protos::pbzero::AndroidLogPriority::PRIO_INFO;
+    int32_t priority = protos::pbzero::AndroidLogPriority::PRIO_INFO;
+    if (message.has_prio()) {
+      priority = ToAndroidLogPriority(
+          static_cast<protos::pbzero::LogMessage::Priority>(message.prio()));
+      inserter->AddArg(parser_->log_message_priority_id_,
+                       Variadic::Integer(priority));
+    }
+
     storage_->mutable_android_log_table()->Insert(
         {ts_, *utid_,
-         /*priority*/ kPriority,
+         /*priority*/ static_cast<uint32_t>(priority),
          /*tag_id*/ source_location_id, log_message_id});
 
     return util::OkStatus();
@@ -1432,6 +1461,8 @@ TrackEventParser::TrackEventParser(TraceProcessorContext* context,
       log_message_source_location_line_number_key_id_(
           context->storage->InternString(
               "track_event.log_message.line_number")),
+      log_message_priority_id_(
+          context->storage->InternString("track_event.priority")),
       source_location_function_name_key_id_(
           context->storage->InternString("source.function_name")),
       source_location_file_name_key_id_(

src/trace_processor/importers/proto/track_event_parser.h

@@ -92,6 +92,7 @@ class TrackEventParser {
   const StringId log_message_source_location_function_name_key_id_;
   const StringId log_message_source_location_file_name_key_id_;
   const StringId log_message_source_location_line_number_key_id_;
+  const StringId log_message_priority_id_;
   const StringId source_location_function_name_key_id_;
   const StringId source_location_file_name_key_id_;
   const StringId source_location_line_number_key_id_;

test/trace_processor/diff_tests/chrome/tests.py

@@ -370,6 +370,62 @@ def test_chrome_log_message(self):
         1,"foo.cc:123","log message",4
         """))
 
+  def test_chrome_log_message_priority(self):
+    return DiffTestBlueprint(
+        trace=TextProto(r"""
+        packet {
+          timestamp: 0
+          incremental_state_cleared: true
+          trusted_packet_sequence_id: 1
+          track_descriptor {
+            uuid: 12345
+            thread {
+              pid: 123
+              tid: 345
+            }
+            parent_uuid: 0
+            chrome_thread {
+              thread_type: THREAD_POOL_FG_WORKER
+            }
+          }
+        }
+
+        packet {
+          trusted_packet_sequence_id: 1
+          timestamp: 10
+          track_event {
+            track_uuid: 12345
+            categories: "cat1"
+            type: TYPE_INSTANT
+            name: "slice1"
+            log_message {
+                body_iid: 1
+                source_location_iid: 3
+                prio: PRIO_WARN
+            }
+          }
+          interned_data {
+            log_message_body {
+                iid: 1
+                body: "log message"
+            }
+            source_locations {
+                iid: 3
+                function_name: "func"
+                file_name: "foo.cc"
+                line_number: 123
+            }
+          }
+        }
+        """),
+        query="""
+        SELECT utid, tag, msg, prio FROM android_logs;
+        """,
+        out=Csv("""
+        "utid","tag","msg","prio"
+        1,"foo.cc:123","log message",5
+        """))
+
   def test_chrome_log_message_args(self):
     return DiffTestBlueprint(
         trace=TextProto(r"""