On Thu, Feb 09, 2023 at 02:20:36PM +0800, Yafang Shao wrote:
[...]
Hi Yafang,
> Many thanks for the detailed analysis. Seems it can work.
>
> Hi John,
>
> Could you pls. try the attached fix ? I have verified it in my test env.
I tested the patch on my environment where I found the issue with newer
kernels + older Perfetto. The patch does improve things so that's nice.
It goes from "not working at all" to "mostly working but missing data"
compared to what happens if I just revert 3087c61ed2c48548b74dd343a5209b87082c682d.
I'm just an end user so can't really speak to the underlying causes but
for those more familiar with how Perfetto works this is what I'm getting:
Error stats for this trace:
name idx source value
---------------------------------------- ---------------------------------------- ---------------------------------------- ----------------------------------------
mismatched_sched_switch_tids [NULL] analysis 11101
systrace_parse_failure [NULL] analysis 19040
The trace explorer window ends up containing the ftrace-specific tracks
but missing the tracks related to Android-specific callbacks and such.
Debug stats below in case they're relevant:
Name Value Type
android_br_parse_errors 0 error (trace)
android_log_format_invalid 0 error (trace)
android_log_num_failed 0 error (trace)
android_log_num_skipped 0 info (trace)
android_log_num_total 0 info (trace)
clock_sync_cache_miss 181 info (analysis)
clock_sync_failure 0 error (analysis)
compact_sched_has_parse_errors 0 error (trace)
compact_sched_switch_skipped 0 info (analysis)
compact_sched_waking_skipped 0 info (analysis)
counter_events_out_of_order 0 error (analysis)
deobfuscate_location_parse_error 0 error (trace)
empty_chrome_metadata 0 error (trace)
energy_breakdown_missing_values 0 error (analysis)
energy_descriptor_invalid 0 error (analysis)
energy_uid_breakdown_missing_values 0 error (analysis)
flow_duplicate_id 0 error (trace)
flow_end_without_start 0 info (trace)
flow_invalid_id 0 error (trace)
flow_no_enclosing_slice 0 error (trace)
flow_step_without_start 0 info (trace)
flow_without_direction 0 error (trace)
frame_timeline_event_parser_errors 0 info (analysis)
ftrace_bundle_tokenizer_errors 0 error (analysis)
ftrace_cpu_bytes_read_begin[0] 0 info (trace)
ftrace_cpu_bytes_read_begin[1] 264 info (trace)
ftrace_cpu_bytes_read_begin[2] 0 info (trace)
ftrace_cpu_bytes_read_begin[3] 224 info (trace)
ftrace_cpu_bytes_read_begin[4] 0 info (trace)
ftrace_cpu_bytes_read_begin[5] 0 info (trace)
ftrace_cpu_bytes_read_begin[6] 0 info (trace)
ftrace_cpu_bytes_read_begin[7] 0 info (trace)
ftrace_cpu_bytes_read_delta[0] 6919836 info (trace)
ftrace_cpu_bytes_read_delta[1] 7197556 info (trace)
ftrace_cpu_bytes_read_delta[2] 6381828 info (trace)
ftrace_cpu_bytes_read_delta[3] 5988336 info (trace)
ftrace_cpu_bytes_read_delta[4] 5933528 info (trace)
ftrace_cpu_bytes_read_delta[5] 4858400 info (trace)
ftrace_cpu_bytes_read_delta[6] 6175260 info (trace)
ftrace_cpu_bytes_read_delta[7] 4633460 info (trace)
ftrace_cpu_bytes_read_end[0] 6919836 info (trace)
ftrace_cpu_bytes_read_end[1] 7197820 info (trace)
ftrace_cpu_bytes_read_end[2] 6381828 info (trace)
ftrace_cpu_bytes_read_end[3] 5988560 info (trace)
ftrace_cpu_bytes_read_end[4] 5933528 info (trace)
ftrace_cpu_bytes_read_end[5] 4858400 info (trace)
ftrace_cpu_bytes_read_end[6] 6175260 info (trace)
ftrace_cpu_bytes_read_end[7] 4633460 info (trace)
ftrace_cpu_commit_overrun_begin[0] 0 info (trace)
ftrace_cpu_commit_overrun_begin[1] 0 info (trace)
ftrace_cpu_commit_overrun_begin[2] 0 info (trace)
ftrace_cpu_commit_overrun_begin[3] 0 info (trace)
ftrace_cpu_commit_overrun_begin[4] 0 info (trace)
ftrace_cpu_commit_overrun_begin[5] 0 info (trace)
ftrace_cpu_commit_overrun_begin[6] 0 info (trace)
ftrace_cpu_commit_overrun_begin[7] 0 info (trace)
ftrace_cpu_commit_overrun_delta[0] 0 error (trace)
ftrace_cpu_commit_overrun_delta[1] 0 error (trace)
ftrace_cpu_commit_overrun_delta[2] 0 error (trace)
ftrace_cpu_commit_overrun_delta[3] 0 error (trace)
ftrace_cpu_commit_overrun_delta[4] 0 error (trace)
ftrace_cpu_commit_overrun_delta[5] 0 error (trace)
ftrace_cpu_commit_overrun_delta[6] 0 error (trace)
ftrace_cpu_commit_overrun_delta[7] 0 error (trace)
ftrace_cpu_commit_overrun_end[0] 0 info (trace)
ftrace_cpu_commit_overrun_end[1] 0 info (trace)
ftrace_cpu_commit_overrun_end[2] 0 info (trace)
ftrace_cpu_commit_overrun_end[3] 0 info (trace)
ftrace_cpu_commit_overrun_end[4] 0 info (trace)
ftrace_cpu_commit_overrun_end[5] 0 info (trace)
ftrace_cpu_commit_overrun_end[6] 0 info (trace)
ftrace_cpu_commit_overrun_end[7] 0 info (trace)
ftrace_cpu_dropped_events_begin[0] 0 info (trace)
ftrace_cpu_dropped_events_begin[1] 0 info (trace)
ftrace_cpu_dropped_events_begin[2] 0 info (trace)
ftrace_cpu_dropped_events_begin[3] 0 info (trace)
ftrace_cpu_dropped_events_begin[4] 0 info (trace)
ftrace_cpu_dropped_events_begin[5] 0 info (trace)
ftrace_cpu_dropped_events_begin[6] 0 info (trace)
ftrace_cpu_dropped_events_begin[7] 0 info (trace)
ftrace_cpu_dropped_events_delta[0] 0 error (trace)
ftrace_cpu_dropped_events_delta[1] 0 error (trace)
ftrace_cpu_dropped_events_delta[2] 0 error (trace)
ftrace_cpu_dropped_events_delta[3] 0 error (trace)
ftrace_cpu_dropped_events_delta[4] 0 error (trace)
ftrace_cpu_dropped_events_delta[5] 0 error (trace)
ftrace_cpu_dropped_events_delta[6] 0 error (trace)
ftrace_cpu_dropped_events_delta[7] 0 error (trace)
ftrace_cpu_dropped_events_end[0] 0 info (trace)
ftrace_cpu_dropped_events_end[1] 0 info (trace)
ftrace_cpu_dropped_events_end[2] 0 info (trace)
ftrace_cpu_dropped_events_end[3] 0 info (trace)
ftrace_cpu_dropped_events_end[4] 0 info (trace)
ftrace_cpu_dropped_events_end[5] 0 info (trace)
ftrace_cpu_dropped_events_end[6] 0 info (trace)
ftrace_cpu_dropped_events_end[7] 0 info (trace)
ftrace_cpu_entries_begin[0] 0 info (trace)
ftrace_cpu_entries_begin[1] 6 info (trace)
ftrace_cpu_entries_begin[2] 0 info (trace)
ftrace_cpu_entries_begin[3] 5 info (trace)
ftrace_cpu_entries_begin[4] 0 info (trace)
ftrace_cpu_entries_begin[5] 0 info (trace)
ftrace_cpu_entries_begin[6] 0 info (trace)
ftrace_cpu_entries_begin[7] 0 info (trace)
ftrace_cpu_entries_delta[0] 6 info (trace)
ftrace_cpu_entries_delta[1] -6 info (trace)
ftrace_cpu_entries_delta[2] 0 info (trace)
ftrace_cpu_entries_delta[3] 2 info (trace)
ftrace_cpu_entries_delta[4] 0 info (trace)
ftrace_cpu_entries_delta[5] 0 info (trace)
ftrace_cpu_entries_delta[6] 0 info (trace)
ftrace_cpu_entries_delta[7] 0 info (trace)
ftrace_cpu_entries_end[0] 6 info (trace)
ftrace_cpu_entries_end[1] 0 info (trace)
ftrace_cpu_entries_end[2] 0 info (trace)
ftrace_cpu_entries_end[3] 7 info (trace)
ftrace_cpu_entries_end[4] 0 info (trace)
ftrace_cpu_entries_end[5] 0 info (trace)
ftrace_cpu_entries_end[6] 0 info (trace)
ftrace_cpu_entries_end[7] 0 info (trace)
ftrace_cpu_now_ts_begin[0] 93305027000 info (trace)
ftrace_cpu_now_ts_begin[1] 93305103000 info (trace)
ftrace_cpu_now_ts_begin[2] 93305159000 info (trace)
ftrace_cpu_now_ts_begin[3] 93305207000 info (trace)
ftrace_cpu_now_ts_begin[4] 93305262000 info (trace)
ftrace_cpu_now_ts_begin[5] 93305312000 info (trace)
ftrace_cpu_now_ts_begin[6] 93305362000 info (trace)
ftrace_cpu_now_ts_begin[7] 93305411000 info (trace)
ftrace_cpu_now_ts_end[0] 282906571000 info (trace)
ftrace_cpu_now_ts_end[1] 282906676000 info (trace)
ftrace_cpu_now_ts_end[2] 282906738000 info (trace)
ftrace_cpu_now_ts_end[3] 282906803000 info (trace)
ftrace_cpu_now_ts_end[4] 282906863000 info (trace)
ftrace_cpu_now_ts_end[5] 282906925000 info (trace)
ftrace_cpu_now_ts_end[6] 282906987000 info (trace)
ftrace_cpu_now_ts_end[7] 282907048000 info (trace)
ftrace_cpu_oldest_event_ts_begin[0] 0 info (trace)
ftrace_cpu_oldest_event_ts_begin[1] 93304642000 info (trace)
ftrace_cpu_oldest_event_ts_begin[2] 0 info (trace)
ftrace_cpu_oldest_event_ts_begin[3] 93304876000 info (trace)
ftrace_cpu_oldest_event_ts_begin[4] 0 info (trace)
ftrace_cpu_oldest_event_ts_begin[5] 0 info (trace)
ftrace_cpu_oldest_event_ts_begin[6] 0 info (trace)
ftrace_cpu_oldest_event_ts_begin[7] 0 info (trace)
ftrace_cpu_oldest_event_ts_end[0] 282905715000 info (trace)
ftrace_cpu_oldest_event_ts_end[1] 282903723000 info (trace)
ftrace_cpu_oldest_event_ts_end[2] 282903881000 info (trace)
ftrace_cpu_oldest_event_ts_end[3] 282816175000 info (trace)
ftrace_cpu_oldest_event_ts_end[4] 282896619000 info (trace)
ftrace_cpu_oldest_event_ts_end[5] 282884168000 info (trace)
ftrace_cpu_oldest_event_ts_end[6] 282783221000 info (trace)
ftrace_cpu_oldest_event_ts_end[7] 282880081000 info (trace)
ftrace_cpu_overrun_begin[0] 0 info (trace)
ftrace_cpu_overrun_begin[1] 0 info (trace)
ftrace_cpu_overrun_begin[2] 0 info (trace)
ftrace_cpu_overrun_begin[3] 0 info (trace)
ftrace_cpu_overrun_begin[4] 0 info (trace)
ftrace_cpu_overrun_begin[5] 0 info (trace)
ftrace_cpu_overrun_begin[6] 0 info (trace)
ftrace_cpu_overrun_begin[7] 0 info (trace)
ftrace_cpu_overrun_delta[0]help_outline 0 data_loss (trace)
ftrace_cpu_overrun_delta[1]help_outline 0 data_loss (trace)
ftrace_cpu_overrun_delta[2]help_outline 0 data_loss (trace)
ftrace_cpu_overrun_delta[3]help_outline 0 data_loss (trace)
ftrace_cpu_overrun_delta[4]help_outline 0 data_loss (trace)
ftrace_cpu_overrun_delta[5]help_outline 0 data_loss (trace)
ftrace_cpu_overrun_delta[6]help_outline 0 data_loss (trace)
ftrace_cpu_overrun_delta[7]help_outline 0 data_loss (trace)
ftrace_cpu_overrun_end[0] 0 info (trace)
ftrace_cpu_overrun_end[1] 0 info (trace)
ftrace_cpu_overrun_end[2] 0 info (trace)
ftrace_cpu_overrun_end[3] 0 info (trace)
ftrace_cpu_overrun_end[4] 0 info (trace)
ftrace_cpu_overrun_end[5] 0 info (trace)
ftrace_cpu_overrun_end[6] 0 info (trace)
ftrace_cpu_overrun_end[7] 0 info (trace)
ftrace_cpu_read_events_begin[0] 0 info (trace)
ftrace_cpu_read_events_begin[1] 0 info (trace)
ftrace_cpu_read_events_begin[2] 0 info (trace)
ftrace_cpu_read_events_begin[3] 0 info (trace)
ftrace_cpu_read_events_begin[4] 0 info (trace)
ftrace_cpu_read_events_begin[5] 0 info (trace)
ftrace_cpu_read_events_begin[6] 0 info (trace)
ftrace_cpu_read_events_begin[7] 0 info (trace)
ftrace_cpu_read_events_delta[0] 454848 info (trace)
ftrace_cpu_read_events_delta[1] 453484 info (trace)
ftrace_cpu_read_events_delta[2] 386290 info (trace)
ftrace_cpu_read_events_delta[3] 356432 info (trace)
ftrace_cpu_read_events_delta[4] 393337 info (trace)
ftrace_cpu_read_events_delta[5] 325244 info (trace)
ftrace_cpu_read_events_delta[6] 392637 info (trace)
ftrace_cpu_read_events_delta[7] 350623 info (trace)
ftrace_cpu_read_events_end[0] 454848 info (trace)
ftrace_cpu_read_events_end[1] 453484 info (trace)
ftrace_cpu_read_events_end[2] 386290 info (trace)
ftrace_cpu_read_events_end[3] 356432 info (trace)
ftrace_cpu_read_events_end[4] 393337 info (trace)
ftrace_cpu_read_events_end[5] 325244 info (trace)
ftrace_cpu_read_events_end[6] 392637 info (trace)
ftrace_cpu_read_events_end[7] 350623 info (trace)
ftrace_packet_before_tracing_starthelp_outline 0 info (analysis)
ftrace_setup_errorshelp_outline 0 error (trace)
fuchsia_invalid_event 0 error (analysis)
fuchsia_non_numeric_counters 0 error (analysis)
fuchsia_timestamp_overflow 0 error (analysis)
game_intervention_has_parse_errorshelp_outline 0 error (trace)
game_intervention_has_read_errorshelp_outline 0 error (trace)
gpu_counters_invalid_spec 0 error (analysis)
gpu_counters_missing_spec 0 error (analysis)
gpu_render_stage_parser_errors 0 error (analysis)
graphics_frame_event_parser_errors 0 info (analysis)
guess_trace_type_duration_ns 7654 info (analysis)
heap_graph_non_finalized_graph 0 error (trace)
heapprofd_missing_packet 0 error (trace)
heapprofd_non_finalized_profile 0 error (trace)
interned_data_tokenizer_errors 0 info (analysis)
invalid_clock_snapshots 0 error (analysis)
invalid_cpu_times 0 error (analysis)
json_display_time_unithelp_outline 0 info (trace)
json_parser_failure 0 error (trace)
json_tokenizer_failure 0 error (trace)
meminfo_unknown_keys 0 error (analysis)
memory_snapshot_parser_failure 0 error (analysis)
metatrace_overruns 0 error (trace)
mismatched_sched_switch_tids 11101 error (analysis)
misplaced_end_event 0 data_loss (analysis)
mm_unknown_type 0 error (analysis)
ninja_parse_errors 0 error (trace)
packages_list_has_parse_errors 0 error (trace)
packages_list_has_read_errors 0 error (trace)
parse_trace_duration_ns 1780589548 info (analysis)
perf_samples_skipped 0 info (trace)
perf_samples_skipped_dataloss 0 data_loss (trace)
power_rail_unknown_index 0 error (trace)
proc_stat_unknown_counters 0 error (analysis)
process_tracker_errors 0 error (analysis)
rss_stat_negative_size 0 info (analysis)
rss_stat_unknown_keys 0 error (analysis)
rss_stat_unknown_thread_for_mm_id 0 info (analysis)
sched_switch_out_of_order 0 error (analysis)
sched_waking_out_of_order 0 error (analysis)
slice_out_of_order 0 error (analysis)
sorter_push_event_out_of_orderhelp_outline 0 error (trace)
stackprofile_invalid_callstack_id 0 error (trace)
stackprofile_invalid_frame_id 0 error (trace)
stackprofile_invalid_mapping_id 0 error (trace)
stackprofile_invalid_string_id 0 error (trace)
stackprofile_parser_error 0 error (trace)
symbolization_tmp_build_id_not_foundhelp_outline 0 error (analysis)
systrace_parse_failure 19040 error (analysis)
task_state_invalid 0 error (analysis)
thread_time_in_state_out_of_order 0 error (analysis)
thread_time_in_state_unknown_cpu_freq 0 error (analysis)
tokenizer_skipped_packets 0 info (analysis)
traced_buf_abi_violations[0] 0 data_loss (trace)
traced_buf_abi_violations[1] 0 data_loss (trace)
traced_buf_buffer_size[0] 534773760 info (trace)
traced_buf_buffer_size[1] 2097152 info (trace)
traced_buf_bytes_overwritten[0] 0 info (trace)
traced_buf_bytes_overwritten[1] 0 info (trace)
traced_buf_bytes_read[0] 78929920 info (trace)
traced_buf_bytes_read[1] 425984 info (trace)
traced_buf_bytes_written[0] 78962688 info (trace)
traced_buf_bytes_written[1] 425984 info (trace)
traced_buf_chunks_committed_out_of_order[0] 0 info (trace)
traced_buf_chunks_committed_out_of_order[1] 0 info (trace)
traced_buf_chunks_discarded[0] 0 info (trace)
traced_buf_chunks_discarded[1] 0 info (trace)
traced_buf_chunks_overwritten[0] 0 info (trace)
traced_buf_chunks_overwritten[1] 0 info (trace)
traced_buf_chunks_read[0] 2428 info (trace)
traced_buf_chunks_read[1] 13 info (trace)
traced_buf_chunks_rewritten[0] 6 info (trace)
traced_buf_chunks_rewritten[1] 0 info (trace)
traced_buf_chunks_written[0] 2429 info (trace)
traced_buf_chunks_written[1] 13 info (trace)
traced_buf_padding_bytes_cleared[0] 0 info (trace)
traced_buf_padding_bytes_cleared[1] 0 info (trace)
traced_buf_padding_bytes_written[0] 0 info (trace)
traced_buf_padding_bytes_written[1] 0 info (trace)
traced_buf_patches_failed[0] 0 data_loss (trace)
traced_buf_patches_failed[1] 0 data_loss (trace)
traced_buf_patches_succeeded[0] 5633 info (trace)
traced_buf_patches_succeeded[1] 8 info (trace)
traced_buf_readaheads_failed[0] 115 info (trace)
traced_buf_readaheads_failed[1] 18 info (trace)
traced_buf_readaheads_succeeded[0] 2257 info (trace)
traced_buf_readaheads_succeeded[1] 6 info (trace)
traced_buf_trace_writer_packet_loss[0] 0 data_loss (trace)
traced_buf_trace_writer_packet_loss[1] 0 data_loss (trace)
traced_buf_write_wrap_count[0] 0 info (trace)
traced_buf_write_wrap_count[1] 0 info (trace)
traced_chunks_discarded 0 info (trace)
traced_data_sources_registered 16 info (trace)
traced_data_sources_seen 6 info (trace)
traced_final_flush_failed 0 data_loss (trace)
traced_final_flush_succeeded 0 info (trace)
traced_flushes_failed 0 data_loss (trace)
traced_flushes_requested 0 info (trace)
traced_flushes_succeeded 0 info (trace)
traced_patches_discarded 0 info (trace)
traced_producers_connected 3 info (trace)
traced_producers_seen 3 info (trace)
traced_total_buffers 2 info (trace)
traced_tracing_sessions 1 info (trace)
track_event_dropped_packets_outside_of_range_of_interesthelp_outline 0 info (analysis)
track_event_parser_errors 0 info (analysis)
track_event_thread_invalid_endhelp_outline 0 error (trace)
track_event_tokenizer_errors 0 info (analysis)
truncated_sys_write_durationhelp_outline 0 data_loss (analysis)
unknown_extension_fieldshelp_outline 0 error (trace)
vmstat_unknown_keys 0 error (analysis)
vulkan_allocations_invalid_string_id 0 error (trace)
> --
> Regards
> Yafang
