| /* |
| * Copyright (C) 2019 The Android Open Source Project |
| * |
| * Licensed under the Apache License, Version 2.0 (the "License"); |
| * you may not use this file except in compliance with the License. |
| * You may obtain a copy of the License at |
| * |
| * http://www.apache.org/licenses/LICENSE-2.0 |
| * |
| * Unless required by applicable law or agreed to in writing, software |
| * distributed under the License is distributed on an "AS IS" BASIS, |
| * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| * See the License for the specific language governing permissions and |
| * limitations under the License. |
| */ |
| |
| #include "src/trace_processor/importers/proto/graphics_frame_event_parser.h" |
| |
| #include <cinttypes> |
| |
| #include "perfetto/ext/base/utils.h" |
| #include "perfetto/protozero/field.h" |
| #include "src/trace_processor/importers/common/args_tracker.h" |
| #include "src/trace_processor/importers/common/event_tracker.h" |
| #include "src/trace_processor/importers/common/process_tracker.h" |
| #include "src/trace_processor/importers/common/slice_tracker.h" |
| #include "src/trace_processor/importers/common/track_tracker.h" |
| #include "src/trace_processor/storage/trace_storage.h" |
| #include "src/trace_processor/types/trace_processor_context.h" |
| |
| #include "protos/perfetto/trace/interned_data/interned_data.pbzero.h" |
| |
| namespace perfetto { |
| namespace trace_processor { |
| |
| constexpr char kQueueLostMessage[] = |
| "Missing queue event. The slice is now a bit extended than it might " |
| "actually have been"; |
| GraphicsFrameEventParser::GraphicsFrameEventParser( |
| TraceProcessorContext* context) |
| : context_(context), |
| graphics_event_scope_id_( |
| context->storage->InternString("graphics_frame_event")), |
| unknown_event_name_id_(context->storage->InternString("unknown_event")), |
| no_layer_name_name_id_(context->storage->InternString("no_layer_name")), |
| layer_name_key_id_(context->storage->InternString("layer_name")), |
| event_type_name_ids_{ |
| {context->storage->InternString( |
| "unspecified_event") /* UNSPECIFIED */, |
| context->storage->InternString("Dequeue") /* DEQUEUE */, |
| context->storage->InternString("Queue") /* QUEUE */, |
| context->storage->InternString("Post") /* POST */, |
| context->storage->InternString( |
| "AcquireFenceSignaled") /* ACQUIRE_FENCE */, |
| context->storage->InternString("Latch") /* LATCH */, |
| context->storage->InternString( |
| "HWCCompositionQueued") /* HWC_COMPOSITION_QUEUED */, |
| context->storage->InternString( |
| "FallbackComposition") /* FALLBACK_COMPOSITION */, |
| context->storage->InternString( |
| "PresentFenceSignaled") /* PRESENT_FENCE */, |
| context->storage->InternString( |
| "ReleaseFenceSignaled") /* RELEASE_FENCE */, |
| context->storage->InternString("Modify") /* MODIFY */, |
| context->storage->InternString("Detach") /* DETACH */, |
| context->storage->InternString("Attach") /* ATTACH */, |
| context->storage->InternString("Cancel") /* CANCEL */}}, |
| queue_lost_message_id_( |
| context->storage->InternString(kQueueLostMessage)) {} |
| |
| bool GraphicsFrameEventParser::CreateBufferEvent( |
| int64_t timestamp, |
| GraphicsFrameEventDecoder& event) { |
| if (!event.has_buffer_id()) { |
| context_->storage->IncrementStats( |
| stats::graphics_frame_event_parser_errors); |
| PERFETTO_ELOG("GraphicsFrameEvent with missing buffer id field."); |
| return false; |
| } |
| |
| // Use buffer id + layer name as key because sometimes the same buffer can be |
| // used by different layers. |
| char event_key_buffer[4096]; |
| base::StringWriter event_key_str(event_key_buffer, |
| base::ArraySize(event_key_buffer)); |
| const uint32_t buffer_id = event.buffer_id(); |
| StringId layer_name_id; |
| event_key_str.AppendUnsignedInt(buffer_id); |
| |
| if (event.has_layer_name()) { |
| layer_name_id = context_->storage->InternString(event.layer_name()); |
| event_key_str.AppendString(base::StringView(event.layer_name())); |
| } else { |
| layer_name_id = no_layer_name_name_id_; |
| } |
| StringId event_key = |
| context_->storage->InternString(event_key_str.GetStringView()); |
| |
| StringId event_name_id = unknown_event_name_id_; |
| if (event.has_type()) { |
| const auto type = static_cast<size_t>(event.type()); |
| if (type < event_type_name_ids_.size()) { |
| event_name_id = event_type_name_ids_[type]; |
| graphics_frame_stats_map_[event_key][type] = timestamp; |
| } else { |
| context_->storage->IncrementStats( |
| stats::graphics_frame_event_parser_errors); |
| PERFETTO_ELOG("GraphicsFrameEvent with unknown type %zu.", type); |
| } |
| } else { |
| context_->storage->IncrementStats( |
| stats::graphics_frame_event_parser_errors); |
| PERFETTO_ELOG("GraphicsFrameEvent with missing type field."); |
| } |
| |
| char buffer[4096]; |
| base::StringWriter track_name(buffer, base::ArraySize(buffer)); |
| track_name.AppendLiteral("Buffer: "); |
| track_name.AppendUnsignedInt(buffer_id); |
| track_name.AppendLiteral(" "); |
| track_name.AppendString(base::StringView(event.layer_name())); |
| |
| const StringId track_name_id = |
| context_->storage->InternString(track_name.GetStringView()); |
| const int64_t duration = |
| event.has_duration_ns() ? static_cast<int64_t>(event.duration_ns()) : 0; |
| uint32_t frame_number = event.has_frame_number() ? event.frame_number() : 0; |
| |
| tables::GpuTrackTable::Row track(track_name_id); |
| track.scope = graphics_event_scope_id_; |
| TrackId track_id = context_->track_tracker->InternGpuTrack(track); |
| |
| auto* graphics_frame_slice_table = |
| context_->storage->mutable_graphics_frame_slice_table(); |
| { |
| tables::GraphicsFrameSliceTable::Row row; |
| row.ts = timestamp; |
| row.track_id = track_id; |
| row.name = event_name_id; |
| row.dur = duration; |
| row.frame_number = frame_number; |
| row.layer_name = layer_name_id; |
| if (event.type() == GraphicsFrameEvent::PRESENT_FENCE) { |
| auto acquire_ts = |
| graphics_frame_stats_map_[event_key] |
| [GraphicsFrameEvent::ACQUIRE_FENCE]; |
| auto queue_ts = |
| graphics_frame_stats_map_[event_key][GraphicsFrameEvent::QUEUE]; |
| auto latch_ts = |
| graphics_frame_stats_map_[event_key][GraphicsFrameEvent::LATCH]; |
| |
| row.queue_to_acquire_time = |
| std::max(acquire_ts - queue_ts, static_cast<int64_t>(0)); |
| row.acquire_to_latch_time = latch_ts - acquire_ts; |
| row.latch_to_present_time = timestamp - latch_ts; |
| } |
| std::optional<SliceId> opt_slice_id = |
| context_->slice_tracker->ScopedTyped(graphics_frame_slice_table, row); |
| if (event.type() == GraphicsFrameEvent::DEQUEUE) { |
| if (opt_slice_id) { |
| dequeue_slice_ids_[event_key] = *opt_slice_id; |
| } |
| } else if (event.type() == GraphicsFrameEvent::QUEUE) { |
| auto it = dequeue_slice_ids_.find(event_key); |
| if (it != dequeue_slice_ids_.end()) { |
| auto dequeue_slice_id = it->second; |
| uint32_t row_idx = |
| *graphics_frame_slice_table->id().IndexOf(dequeue_slice_id); |
| graphics_frame_slice_table->mutable_frame_number()->Set(row_idx, |
| frame_number); |
| } |
| } |
| } |
| return true; |
| } |
| |
| void GraphicsFrameEventParser::InvalidatePhaseEvent(int64_t timestamp, |
| TrackId track_id, |
| bool reset_name) { |
| const auto opt_slice_id = context_->slice_tracker->End(timestamp, track_id); |
| |
| if (opt_slice_id) { |
| auto* graphics_frame_slice_table = |
| context_->storage->mutable_graphics_frame_slice_table(); |
| uint32_t row_idx = *graphics_frame_slice_table->id().IndexOf(*opt_slice_id); |
| if (reset_name) { |
| // Set the name (frame_number) to be 0 since there is no frame number |
| // associated, example : dequeue event. |
| StringId frame_name_id = context_->storage->InternString("0"); |
| graphics_frame_slice_table->mutable_name()->Set(row_idx, frame_name_id); |
| graphics_frame_slice_table->mutable_frame_number()->Set(row_idx, 0); |
| } |
| |
| // Set the duration to -1 so that this slice will be ignored by the |
| // UI. Setting any other duration results in wrong data which we want |
| // to avoid at all costs. |
| graphics_frame_slice_table->mutable_dur()->Set(row_idx, -1); |
| } |
| } |
| |
| // Here we convert the buffer events into Phases(slices) |
| // APP: Dequeue to Queue |
| // Wait for GPU: Queue to Acquire |
| // SurfaceFlinger (SF): Latch to Present |
| // Display: Present to next Present (of the same layer) |
| void GraphicsFrameEventParser::CreatePhaseEvent( |
| int64_t timestamp, |
| GraphicsFrameEventDecoder& event) { |
| // Use buffer id + layer name as key because sometimes the same buffer can be |
| // used by different layers. |
| char event_key_buffer[4096]; |
| base::StringWriter event_key_str(event_key_buffer, |
| base::ArraySize(event_key_buffer)); |
| const uint32_t buffer_id = event.buffer_id(); |
| uint32_t frame_number = event.has_frame_number() ? event.frame_number() : 0; |
| event_key_str.AppendUnsignedInt(buffer_id); |
| StringId layer_name_id; |
| if (event.has_layer_name()) { |
| layer_name_id = context_->storage->InternString(event.layer_name()); |
| event_key_str.AppendString(base::StringView(event.layer_name())); |
| } else { |
| layer_name_id = no_layer_name_name_id_; |
| } |
| StringId event_key = |
| context_->storage->InternString(event_key_str.GetStringView()); |
| |
| char track_buffer[4096]; |
| char slice_buffer[4096]; |
| // We'll be using the name StringWriter and name_id for writing track names |
| // and slice names. |
| base::StringWriter track_name(track_buffer, base::ArraySize(track_buffer)); |
| base::StringWriter slice_name(slice_buffer, base::ArraySize(slice_buffer)); |
| StringId track_name_id; |
| TrackId track_id; |
| bool start_slice = true; |
| |
| // Close the previous phase before starting the new phase |
| switch (event.type()) { |
| case GraphicsFrameEvent::DEQUEUE: { |
| track_name.reset(); |
| track_name.AppendLiteral("APP_"); |
| track_name.AppendUnsignedInt(buffer_id); |
| track_name.AppendLiteral(" "); |
| track_name.AppendString(base::StringView(event.layer_name())); |
| track_name_id = |
| context_->storage->InternString(track_name.GetStringView()); |
| tables::GpuTrackTable::Row app_track(track_name_id); |
| app_track.scope = graphics_event_scope_id_; |
| track_id = context_->track_tracker->InternGpuTrack(app_track); |
| |
| // Error handling |
| auto dequeue_time = dequeue_map_.find(event_key); |
| if (dequeue_time != dequeue_map_.end()) { |
| InvalidatePhaseEvent(timestamp, dequeue_time->second, true); |
| dequeue_map_.erase(dequeue_time); |
| } |
| auto queue_time = queue_map_.find(event_key); |
| if (queue_time != queue_map_.end()) { |
| InvalidatePhaseEvent(timestamp, queue_time->second); |
| queue_map_.erase(queue_time); |
| } |
| |
| dequeue_map_[event_key] = track_id; |
| last_dequeued_[event_key] = timestamp; |
| break; |
| } |
| |
| case GraphicsFrameEvent::QUEUE: { |
| auto dequeue_time = dequeue_map_.find(event_key); |
| if (dequeue_time != dequeue_map_.end()) { |
| const auto opt_slice_id = |
| context_->slice_tracker->End(timestamp, dequeue_time->second); |
| slice_name.reset(); |
| slice_name.AppendUnsignedInt(frame_number); |
| if (opt_slice_id) { |
| auto* graphics_frame_slice_table = |
| context_->storage->mutable_graphics_frame_slice_table(); |
| // Set the name of the slice to be the frame number since dequeue did |
| // not have a frame number at that time. |
| uint32_t row_idx = |
| *graphics_frame_slice_table->id().IndexOf(*opt_slice_id); |
| StringId frame_name_id = |
| context_->storage->InternString(slice_name.GetStringView()); |
| graphics_frame_slice_table->mutable_name()->Set(row_idx, |
| frame_name_id); |
| graphics_frame_slice_table->mutable_frame_number()->Set(row_idx, |
| frame_number); |
| dequeue_map_.erase(dequeue_time); |
| } |
| } |
| // The AcquireFence might be signaled before receiving a QUEUE event |
| // sometimes. In that case, we shouldn't start a slice. |
| if (last_acquired_[event_key] > last_dequeued_[event_key] && |
| last_acquired_[event_key] < timestamp) { |
| start_slice = false; |
| break; |
| } |
| track_name.reset(); |
| track_name.AppendLiteral("GPU_"); |
| track_name.AppendUnsignedInt(buffer_id); |
| track_name.AppendLiteral(" "); |
| track_name.AppendString(base::StringView(event.layer_name())); |
| track_name_id = |
| context_->storage->InternString(track_name.GetStringView()); |
| tables::GpuTrackTable::Row gpu_track(track_name_id); |
| gpu_track.scope = graphics_event_scope_id_; |
| track_id = context_->track_tracker->InternGpuTrack(gpu_track); |
| queue_map_[event_key] = track_id; |
| break; |
| } |
| case GraphicsFrameEvent::ACQUIRE_FENCE: { |
| auto queue_time = queue_map_.find(event_key); |
| if (queue_time != queue_map_.end()) { |
| context_->slice_tracker->End(timestamp, queue_time->second); |
| queue_map_.erase(queue_time); |
| } |
| last_acquired_[event_key] = timestamp; |
| start_slice = false; |
| break; |
| } |
| case GraphicsFrameEvent::LATCH: { |
| // b/157578286 - Sometimes Queue event goes missing. To prevent having a |
| // wrong slice info, we try to close any existing APP slice. |
| auto dequeue_time = dequeue_map_.find(event_key); |
| if (dequeue_time != dequeue_map_.end()) { |
| InvalidatePhaseEvent(timestamp, dequeue_time->second, true); |
| dequeue_map_.erase(dequeue_time); |
| } |
| track_name.reset(); |
| track_name.AppendLiteral("SF_"); |
| track_name.AppendUnsignedInt(buffer_id); |
| track_name.AppendLiteral(" "); |
| track_name.AppendString(base::StringView(event.layer_name())); |
| track_name_id = |
| context_->storage->InternString(track_name.GetStringView()); |
| tables::GpuTrackTable::Row sf_track(track_name_id); |
| sf_track.scope = graphics_event_scope_id_; |
| track_id = context_->track_tracker->InternGpuTrack(sf_track); |
| latch_map_[event_key] = track_id; |
| break; |
| } |
| |
| case GraphicsFrameEvent::PRESENT_FENCE: { |
| auto latch_time = latch_map_.find(event_key); |
| if (latch_time != latch_map_.end()) { |
| context_->slice_tracker->End(timestamp, latch_time->second); |
| latch_map_.erase(latch_time); |
| } |
| auto display_time = display_map_.find(layer_name_id); |
| if (display_time != display_map_.end()) { |
| context_->slice_tracker->End(timestamp, display_time->second); |
| display_map_.erase(display_time); |
| } |
| base::StringView layerName(event.layer_name()); |
| track_name.reset(); |
| track_name.AppendLiteral("Display_"); |
| track_name.AppendString(layerName.substr(0, 10)); |
| track_name_id = |
| context_->storage->InternString(track_name.GetStringView()); |
| tables::GpuTrackTable::Row display_track(track_name_id); |
| display_track.scope = graphics_event_scope_id_; |
| track_id = context_->track_tracker->InternGpuTrack(display_track); |
| display_map_[layer_name_id] = track_id; |
| break; |
| } |
| |
| default: |
| start_slice = false; |
| } |
| |
| // Start the new phase if needed. |
| if (start_slice) { |
| tables::GraphicsFrameSliceTable::Row slice; |
| slice.ts = timestamp; |
| slice.track_id = track_id; |
| slice.layer_name = layer_name_id; |
| slice_name.reset(); |
| // If the frame_number is known, set it as the name of the slice. |
| // If not known (DEQUEUE), set the name as the timestamp. |
| // Timestamp is chosen here because the stack_id is hashed based on the name |
| // of the slice. To not have any conflicting stack_id with any of the |
| // existing slices, we use timestamp as the temporary name. |
| if (frame_number != 0) { |
| slice_name.AppendUnsignedInt(frame_number); |
| } else { |
| slice_name.AppendInt(timestamp); |
| } |
| slice.name = context_->storage->InternString(slice_name.GetStringView()); |
| slice.frame_number = frame_number; |
| context_->slice_tracker->BeginTyped( |
| context_->storage->mutable_graphics_frame_slice_table(), slice); |
| } |
| } |
| |
| void GraphicsFrameEventParser::ParseGraphicsFrameEvent(int64_t timestamp, |
| ConstBytes blob) { |
| protos::pbzero::GraphicsFrameEvent_Decoder frame_event(blob.data, blob.size); |
| if (!frame_event.has_buffer_event()) { |
| return; |
| } |
| |
| ConstBytes bufferBlob = frame_event.buffer_event(); |
| protos::pbzero::GraphicsFrameEvent_BufferEvent_Decoder event(bufferBlob.data, |
| bufferBlob.size); |
| if (CreateBufferEvent(timestamp, event)) { |
| // Create a phase event only if the buffer event finishes successfully |
| CreatePhaseEvent(timestamp, event); |
| } |
| } |
| |
| } // namespace trace_processor |
| } // namespace perfetto |
