diff options
author | android-build-team Robot <android-build-team-robot@google.com> | 2021-05-19 01:04:32 +0000 |
---|---|---|
committer | android-build-team Robot <android-build-team-robot@google.com> | 2021-05-19 01:04:32 +0000 |
commit | 4c97f1e99ab8ca148f14d8da77778068405aea0b (patch) | |
tree | 3be250b4d73ed89bbf9514f6e9b15eb8717f1e11 | |
parent | 3be76dcd4b2bede9d74dbd7021ce19017290d07c (diff) | |
parent | bbedffa9bcf6dca3533c142e523722cb79bc1ba2 (diff) | |
download | perfetto-4c97f1e99ab8ca148f14d8da77778068405aea0b.tar.gz |
Snap for 7374840 from bbedffa9bcf6dca3533c142e523722cb79bc1ba2 to sc-d2-release
Change-Id: I68eecfd461e3509fe2e42e4268d1d65e1107b3e0
44 files changed, 747 insertions, 38 deletions
diff --git a/Android.bp b/Android.bp index 99e63bb22..7f8b8e072 100644 --- a/Android.bp +++ b/Android.bp @@ -7436,6 +7436,7 @@ filegroup { srcs: [ "src/protozero/filtering/filter_bytecode_generator_unittest.cc", "src/protozero/filtering/filter_bytecode_parser_unittest.cc", + "src/protozero/filtering/message_tokenizer_unittest.cc", ], } diff --git a/debian/changelog b/debian/changelog index fb48257cd..2b4ba124b 100644 --- a/debian/changelog +++ b/debian/changelog @@ -1,3 +1,11 @@ +perfetto (15.0-1) unstable; urgency=medium + * Performance improvements. + * Bugfixes. + * More flexible SDK. + * New data-sources. + + -- Florian Mayer <fmayer@google.com> Fri, 14 May 2021 10:50:00 +0000 + perfetto (11.0-1) unstable; urgency=medium * Add the Perfetto perf sampling and profiling service. diff --git a/debian/compat b/debian/compat index f599e28b8..b1bd38b62 100644 --- a/debian/compat +++ b/debian/compat @@ -1 +1 @@ -10 +13 diff --git a/debian/control b/debian/control index 28fcef21f..94a03bb38 100644 --- a/debian/control +++ b/debian/control @@ -2,7 +2,7 @@ Source: perfetto Section: kernel Priority: optional Maintainer: Sami Kyostila <skyostil@google.com> -Build-Depends: debhelper (>= 10), +Build-Depends: debhelper (>= 13), generate-ninja, git, libprotoc-dev, @@ -11,14 +11,15 @@ Build-Depends: debhelper (>= 10), python3, zlib1g-dev, zlib1g -Standards-Version: 3.9.8 +Standards-Version: 4.5.1 Homepage: https://perfetto.dev Vcs-Git: https://android.googlesource.com/platform/external/perfetto/ Vcs-Browser: https://android.googlesource.com/platform/external/perfetto/ +Rules-Requires-Root: no Package: perfetto Architecture: any -Depends: ${shlibs:Depends}, ${misc:Depends}, zlib1g +Depends: ${shlibs:Depends}, ${misc:Depends}, adduser, zlib1g Description: Performance instrumentation and logging framework Perfetto is a performance instrumentation and logging framework for POSIX systems. diff --git a/debian/copyright b/debian/copyright index e23f57db5..7b7058c56 100644 --- a/debian/copyright +++ b/debian/copyright @@ -4,12 +4,12 @@ Source: https://android.googlesource.com/platform/external/perfetto/ Files: * Copyright: Copyright (C) 2017 The Android Open Source Project -License: Apache 2 +License: Apache-2 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 + /usr/share/common-licenses/Apache-2.0 . Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, diff --git a/debian/gitlab-ci.yml b/debian/gitlab-ci.yml new file mode 100644 index 000000000..892f3cd2b --- /dev/null +++ b/debian/gitlab-ci.yml @@ -0,0 +1,3 @@ +include: + - https://salsa.debian.org/salsa-ci-team/pipeline/raw/master/salsa-ci.yml + - https://salsa.debian.org/salsa-ci-team/pipeline/raw/master/pipeline-jobs.yml diff --git a/debian/postinst b/debian/postinst index 7d7e26662..e6cdff56a 100755 --- a/debian/postinst +++ b/debian/postinst @@ -3,3 +3,5 @@ set -e adduser --home /nonexistent --quiet --system --no-create-home --group traced addgroup --quiet --system traced-consumer usermod -a -G traced-consumer traced + +#DEBHELPER# diff --git a/debian/postrm b/debian/postrm index 20c97672b..efa15906d 100755 --- a/debian/postrm +++ b/debian/postrm @@ -1,3 +1,5 @@ #!/bin/sh set -e rm -f /tmp/perfetto-consumer /tmp/perfetto-producer + +#DEBHELPER# diff --git a/debian/rules b/debian/rules index a5d61997f..a081c5caf 100755 --- a/debian/rules +++ b/debian/rules @@ -1,15 +1,36 @@ #!/usr/bin/make -f + +export DEB_BUILD_MAINT_OPTIONS = hardening=+all +DPKG_EXPORT_BUILDFLAGS = 1 +include /usr/share/dpkg/buildflags.mk + %: dh $@ +override_dh_auto_configure: MAYBE_HOST_CPU=$(shell \ + if [ "${DEB_BUILD_GNU_CPU}" = "i686" ]; then \ + echo "host_cpu=\\\"x86\\\"";\ + elif [ "${DEB_BUILD_GNU_CPU}" = "x86_64" ]; then \ + echo "host_cpu=\\\"x64\\\"";\ + elif [ "${DEB_BUILD_GNU_CPU}" = "aarch64" ]; then \ + echo "host_cpu=\\\"arm64\\\"";\ + elif [ "${DEB_BUILD_GNU_CPU}" = "arm64" ]; then \ + echo "host_cpu=\\\"arm64\\\"";\ + elif [ "${DEB_BUILD_GNU_CPU:0:3}" == "arm" ]; then \ + echo "host_cpu=\\\"arm\\\"";\ + fi\ +) override_dh_auto_configure: + env + uname -a gn gen out/release --args="is_debug=false use_custom_libcxx=false\ is_hermetic_clang=false is_system_compiler=true is_clang=false\ skip_buildtools_check=true enable_perfetto_integration_tests=false\ enable_perfetto_unittests=false perfetto_use_system_protobuf=true\ perfetto_use_system_zlib=true perfetto_enable_git_rev_version_header=false\ extra_cflags=\"${CFLAGS}\" extra_cxxflags=\"${CXXFLAGS}\"\ - extra_ldflags=\"${CXXFLAGS}\" cc=\"${CC}\" cxx=\"${CXX}\"" + extra_ldflags=\"${LDFLAGS}\" cc=\"${CC}\" cxx=\"${CXX}\"\ + ${MAYBE_HOST_CPU}" override_dh_auto_build: ninja -C out/release perfetto traced traced_probes diff --git a/debian/traced-perf.service b/debian/traced-perf.service index b04463b99..73bffb94f 100644 --- a/debian/traced-perf.service +++ b/debian/traced-perf.service @@ -1,5 +1,6 @@ [Unit] Description=Perfetto sampling and profiling data source +Documentation=https://perfetto.dev/docs/ [Service] ExecStart=/usr/sbin/traced_perf diff --git a/debian/traced-probes.service b/debian/traced-probes.service index 81a23f7ce..1d853b0a7 100644 --- a/debian/traced-probes.service +++ b/debian/traced-probes.service @@ -1,5 +1,6 @@ [Unit] Description=Perfetto data sources for system tracing (ftrace and /proc pollers) +Documentation=https://perfetto.dev/docs/ [Service] ExecStart=/usr/sbin/traced_probes diff --git a/debian/traced.service b/debian/traced.service index 6eb7d8a4f..4ca8d7a7c 100644 --- a/debian/traced.service +++ b/debian/traced.service @@ -1,5 +1,6 @@ [Unit] Description=Perfetto tracing service daemon +Documentation=https://perfetto.dev/docs/ [Service] ExecStart=/usr/sbin/traced \ diff --git a/include/perfetto/ext/base/thread_task_runner.h b/include/perfetto/ext/base/thread_task_runner.h index d4e672e58..5f5947eb0 100644 --- a/include/perfetto/ext/base/thread_task_runner.h +++ b/include/perfetto/ext/base/thread_task_runner.h @@ -32,7 +32,7 @@ namespace base { // * the UnixTaskRunner will be constructed and destructed on the task thread. // * the task thread will live for the lifetime of the UnixTaskRunner. // -class ThreadTaskRunner : public TaskRunner { +class PERFETTO_EXPORT ThreadTaskRunner : public TaskRunner { public: static ThreadTaskRunner CreateAndStart(const std::string& name = "") { return ThreadTaskRunner(name); diff --git a/protos/perfetto/config/perfetto_config.proto b/protos/perfetto/config/perfetto_config.proto index 529adc798..d088e9b84 100644 --- a/protos/perfetto/config/perfetto_config.proto +++ b/protos/perfetto/config/perfetto_config.proto @@ -621,6 +621,12 @@ message HeapprofdConfig { // Introduced in Android 12. repeated string heaps = 20; + // Which heaps not to sample, e.g. "libc.malloc". This is useful when used in + // combination with all_heaps; + // + // Introduced in Android 12. + repeated string exclude_heaps = 27; + optional bool stream_allocations = 23; // If given, needs to be the same length as heaps and gives the sampling diff --git a/protos/perfetto/config/profiling/heapprofd_config.proto b/protos/perfetto/config/profiling/heapprofd_config.proto index 2d8654c65..00dd6929c 100644 --- a/protos/perfetto/config/profiling/heapprofd_config.proto +++ b/protos/perfetto/config/profiling/heapprofd_config.proto @@ -81,6 +81,12 @@ message HeapprofdConfig { // Introduced in Android 12. repeated string heaps = 20; + // Which heaps not to sample, e.g. "libc.malloc". This is useful when used in + // combination with all_heaps; + // + // Introduced in Android 12. + repeated string exclude_heaps = 27; + optional bool stream_allocations = 23; // If given, needs to be the same length as heaps and gives the sampling diff --git a/protos/perfetto/metrics/android/startup_metric.proto b/protos/perfetto/metrics/android/startup_metric.proto index 22a67d322..54bf1d74a 100644 --- a/protos/perfetto/metrics/android/startup_metric.proto +++ b/protos/perfetto/metrics/android/startup_metric.proto @@ -128,6 +128,11 @@ message AndroidStartupMetric { reserved 3; } + message BinderTransaction { + optional Slice duration = 1; + optional string thread = 2; + } + // Metrics with information about the status of odex files and the outcome // of the loading process. // Multiple files might be loaded for a single startup. Platform might also @@ -147,7 +152,7 @@ message AndroidStartupMetric { optional int64 first_frame = 2; } - // Next id: 14 + // Next id: 15 message Startup { // Random id uniquely identifying an app startup in this trace. optional uint32 startup_id = 1; @@ -161,6 +166,10 @@ message AndroidStartupMetric { // Details about the activities launched repeated Activity activities = 11; + // Details about slow binder transactions during the startup. The definition + // of a slow transaction is an implementation detail. + repeated BinderTransaction long_binder_transactions = 14; + // Did we ask the zygote for a new process optional bool zygote_new_process = 4; diff --git a/protos/perfetto/metrics/perfetto_merged_metrics.proto b/protos/perfetto/metrics/perfetto_merged_metrics.proto index ff04bf069..dc2196e4a 100644 --- a/protos/perfetto/metrics/perfetto_merged_metrics.proto +++ b/protos/perfetto/metrics/perfetto_merged_metrics.proto @@ -793,6 +793,11 @@ message AndroidStartupMetric { reserved 3; } + message BinderTransaction { + optional Slice duration = 1; + optional string thread = 2; + } + // Metrics with information about the status of odex files and the outcome // of the loading process. // Multiple files might be loaded for a single startup. Platform might also @@ -812,7 +817,7 @@ message AndroidStartupMetric { optional int64 first_frame = 2; } - // Next id: 14 + // Next id: 15 message Startup { // Random id uniquely identifying an app startup in this trace. optional uint32 startup_id = 1; @@ -826,6 +831,10 @@ message AndroidStartupMetric { // Details about the activities launched repeated Activity activities = 11; + // Details about slow binder transactions during the startup. The definition + // of a slow transaction is an implementation detail. + repeated BinderTransaction long_binder_transactions = 14; + // Did we ask the zygote for a new process optional bool zygote_new_process = 4; diff --git a/protos/perfetto/trace/perfetto_trace.proto b/protos/perfetto/trace/perfetto_trace.proto index b5c30d118..36313affd 100644 --- a/protos/perfetto/trace/perfetto_trace.proto +++ b/protos/perfetto/trace/perfetto_trace.proto @@ -621,6 +621,12 @@ message HeapprofdConfig { // Introduced in Android 12. repeated string heaps = 20; + // Which heaps not to sample, e.g. "libc.malloc". This is useful when used in + // combination with all_heaps; + // + // Introduced in Android 12. + repeated string exclude_heaps = 27; + optional bool stream_allocations = 23; // If given, needs to be the same length as heaps and gives the sampling @@ -6587,6 +6593,9 @@ message ChromeFrameReporter { // Whether the frame contained any missing content (i.e. whether there was // checkerboarding in the frame). optional bool has_missing_content = 10; + + // The id of layer_tree_host that the frame has been produced for. + optional uint64 layer_tree_host_id = 11; } // End of protos/perfetto/trace/track_event/chrome_frame_reporter.proto diff --git a/protos/perfetto/trace/track_event/chrome_frame_reporter.proto b/protos/perfetto/trace/track_event/chrome_frame_reporter.proto index 10a129388..00930c7f6 100644 --- a/protos/perfetto/trace/track_event/chrome_frame_reporter.proto +++ b/protos/perfetto/trace/track_event/chrome_frame_reporter.proto @@ -91,4 +91,7 @@ message ChromeFrameReporter { // Whether the frame contained any missing content (i.e. whether there was // checkerboarding in the frame). optional bool has_missing_content = 10; + + // The id of layer_tree_host that the frame has been produced for. + optional uint64 layer_tree_host_id = 11; } diff --git a/src/base/test/utils.cc b/src/base/test/utils.cc index a5ca116e5..0a5661162 100644 --- a/src/base/test/utils.cc +++ b/src/base/test/utils.cc @@ -18,6 +18,8 @@ #include <stdlib.h> +#include <memory> + #include "perfetto/base/build_config.h" #include "perfetto/base/logging.h" #include "perfetto/ext/base/file_utils.h" @@ -82,5 +84,28 @@ std::string GetTestDataPath(const std::string& path) { return path; } +std::string HexDump(const void* data_void, size_t len, size_t bytes_per_line) { + const char* data = reinterpret_cast<const char*>(data_void); + std::string res; + static const size_t kPadding = bytes_per_line * 3 + 12; + std::unique_ptr<char[]> line(new char[bytes_per_line * 4 + 128]); + for (size_t i = 0; i < len; i += bytes_per_line) { + char* wptr = line.get(); + wptr += sprintf(wptr, "%08zX: ", i); + for (size_t j = i; j < i + bytes_per_line && j < len; j++) + wptr += sprintf(wptr, "%02X ", static_cast<unsigned>(data[j]) & 0xFF); + for (size_t j = static_cast<size_t>(wptr - line.get()); j < kPadding; ++j) + *(wptr++) = ' '; + for (size_t j = i; j < i + bytes_per_line && j < len; j++) { + char c = data[j]; + *(wptr++) = (c >= 32 && c < 127) ? c : '.'; + } + *(wptr++) = '\n'; + *(wptr++) = '\0'; + res.append(line.get()); + } + return res; +} + } // namespace base } // namespace perfetto diff --git a/src/base/test/utils.h b/src/base/test/utils.h index 365c93f10..e53b7863d 100644 --- a/src/base/test/utils.h +++ b/src/base/test/utils.h @@ -37,9 +37,9 @@ // we just fall back on executing the code directly. #if defined(GTEST_EXECUTE_STATEMENT_) #define EXPECT_DCHECK_DEATH(statement) \ - GTEST_EXECUTE_STATEMENT_(statement, "PERFETTO_CHECK") + GTEST_EXECUTE_STATEMENT_(statement, "PERFETTO_CHECK") #define ASSERT_DCHECK_DEATH(statement) \ - GTEST_EXECUTE_STATEMENT_(statement, "PERFETTO_CHECK") + GTEST_EXECUTE_STATEMENT_(statement, "PERFETTO_CHECK") #else #define EXPECT_DCHECK_DEATH(statement) [&]() { statement }() #define ASSERT_DCHECK_DEATH(statement) [&]() { statement }() @@ -53,6 +53,13 @@ namespace base { std::string GetCurExecutableDir(); std::string GetTestDataPath(const std::string& path); +// Returns a xxd-style hex dump (hex + ascii chars) of the input data. +std::string HexDump(const void* data, size_t len, size_t bytes_per_line = 16); +inline std::string HexDump(const std::string& data, + size_t bytes_per_line = 16) { + return HexDump(data.data(), data.size(), bytes_per_line); +} + } // namespace base } // namespace perfetto diff --git a/src/profiling/memory/heapprofd_producer.cc b/src/profiling/memory/heapprofd_producer.cc index 16da1faa6..dfc69222c 100644 --- a/src/profiling/memory/heapprofd_producer.cc +++ b/src/profiling/memory/heapprofd_producer.cc @@ -149,10 +149,13 @@ bool HeapprofdConfigToClientConfiguration( cli_config->adaptive_sampling_max_sampling_interval_bytes = heapprofd_config.adaptive_sampling_max_sampling_interval_bytes(); size_t n = 0; + const std::vector<std::string>& exclude_heaps = heapprofd_config.exclude_heaps(); + // heaps[i] and heaps_interval[i] represent that the heap named in heaps[i] + // should be sampled with sampling interval of heap_interval[i]. std::vector<std::string> heaps = heapprofd_config.heaps(); std::vector<uint64_t> heap_intervals = heapprofd_config.heap_sampling_intervals(); - if (heaps.empty()) { + if (heaps.empty() && !cli_config->all_heaps) { heaps.push_back("libc.malloc"); } @@ -169,6 +172,15 @@ bool HeapprofdConfigToClientConfiguration( PERFETTO_ELOG("zero sampling interval."); return false; } + if (!exclude_heaps.empty()) { + // For disabled heaps, we add explicit entries but with sampling interval + // 0. The consumer of the sampling intervals in ClientConfiguration, + // GetSamplingInterval in wire_protocol.h, uses 0 to signal a heap is + // disabled, either because it isn't enabled (all_heaps is not set, and the + // heap isn't named), or because we explicitely set it here. + heaps.insert(heaps.end(), exclude_heaps.cbegin(), exclude_heaps.cend()); + heap_intervals.insert(heap_intervals.end(), exclude_heaps.size(), 0u); + } if (heaps.size() > base::ArraySize(cli_config->heaps)) { heaps.resize(base::ArraySize(cli_config->heaps)); PERFETTO_ELOG("Too many heaps requested. Truncating."); diff --git a/src/profiling/memory/heapprofd_producer_unittest.cc b/src/profiling/memory/heapprofd_producer_unittest.cc index 8a751451a..fa08e95f9 100644 --- a/src/profiling/memory/heapprofd_producer_unittest.cc +++ b/src/profiling/memory/heapprofd_producer_unittest.cc @@ -202,5 +202,42 @@ TEST(HeapprofdConfigToClientConfigurationTest, AdaptiveSamplingWithMax) { 4 * 4096u); } +TEST(HeapprofdConfigToClientConfigurationTest, AllHeaps) { + HeapprofdConfig cfg; + cfg.set_all_heaps(true); + cfg.set_sampling_interval_bytes(4096); + ClientConfiguration cli_config; + ASSERT_TRUE(HeapprofdConfigToClientConfiguration(cfg, &cli_config)); + EXPECT_EQ(cli_config.num_heaps, 0u); + EXPECT_EQ(cli_config.default_interval, 4096u); +} + +TEST(HeapprofdConfigToClientConfigurationTest, AllHeapsAndExplicit) { + HeapprofdConfig cfg; + cfg.set_all_heaps(true); + cfg.set_sampling_interval_bytes(4096); + cfg.add_heaps("foo"); + cfg.add_heap_sampling_intervals(1024u); + ClientConfiguration cli_config; + ASSERT_TRUE(HeapprofdConfigToClientConfiguration(cfg, &cli_config)); + EXPECT_EQ(cli_config.num_heaps, 1u); + EXPECT_STREQ(cli_config.heaps[0].name, "foo"); + EXPECT_EQ(cli_config.heaps[0].interval, 1024u); + EXPECT_EQ(cli_config.default_interval, 4096u); +} + +TEST(HeapprofdConfigToClientConfigurationTest, AllHeapsAndDisabled) { + HeapprofdConfig cfg; + cfg.set_all_heaps(true); + cfg.set_sampling_interval_bytes(4096); + cfg.add_exclude_heaps("foo"); + ClientConfiguration cli_config; + ASSERT_TRUE(HeapprofdConfigToClientConfiguration(cfg, &cli_config)); + EXPECT_EQ(cli_config.num_heaps, 1u); + EXPECT_STREQ(cli_config.heaps[0].name, "foo"); + EXPECT_EQ(cli_config.heaps[0].interval, 0u); + EXPECT_EQ(cli_config.default_interval, 4096u); +} + } // namespace profiling } // namespace perfetto diff --git a/src/profiling/memory/wire_protocol_unittest.cc b/src/profiling/memory/wire_protocol_unittest.cc index 69df58fce..3f7e494dd 100644 --- a/src/profiling/memory/wire_protocol_unittest.cc +++ b/src/profiling/memory/wire_protocol_unittest.cc @@ -160,6 +160,17 @@ TEST(GetHeapSamplingInterval, SelectedAndDefault) { EXPECT_EQ(GetHeapSamplingInterval(cli_config, "else"), 1u); } +TEST(GetHeapSamplingInterval, DisabledAndDefault) { + ClientConfiguration cli_config{}; + cli_config.all_heaps = true; + cli_config.num_heaps = 1; + cli_config.default_interval = 1; + memcpy(cli_config.heaps[0].name, "something", sizeof("something")); + cli_config.heaps[0].interval = 0u; + EXPECT_EQ(GetHeapSamplingInterval(cli_config, "something"), 0u); + EXPECT_EQ(GetHeapSamplingInterval(cli_config, "else"), 1u); +} + } // namespace } // namespace profiling } // namespace perfetto diff --git a/src/protozero/filtering/BUILD.gn b/src/protozero/filtering/BUILD.gn index 07489a88b..0ddfc3eff 100644 --- a/src/protozero/filtering/BUILD.gn +++ b/src/protozero/filtering/BUILD.gn @@ -58,6 +58,7 @@ perfetto_unittest_source_set("unittests") { sources = [ "filter_bytecode_generator_unittest.cc", "filter_bytecode_parser_unittest.cc", + "message_tokenizer_unittest.cc", ] } diff --git a/src/protozero/filtering/filter_bytecode_parser.cc b/src/protozero/filtering/filter_bytecode_parser.cc index 6bd1e769f..1a1d32fe8 100644 --- a/src/protozero/filtering/filter_bytecode_parser.cc +++ b/src/protozero/filtering/filter_bytecode_parser.cc @@ -172,8 +172,10 @@ FilterBytecodeParser::QueryResult FilterBytecodeParser::Query( uint32_t msg_index, uint32_t field_id) { FilterBytecodeParser::QueryResult res{false, 0u}; - if (msg_index >= message_offset_.size() - 1) + if (static_cast<uint64_t>(msg_index) + 1 >= + static_cast<uint64_t>(message_offset_.size())) { return res; + } const uint32_t start_offset = message_offset_[msg_index]; // These are DCHECKs and not just CHECKS because the |words_| is populated // by the LoadInternal call above. These cannot be violated with a malformed diff --git a/src/protozero/filtering/filter_bytecode_parser_unittest.cc b/src/protozero/filtering/filter_bytecode_parser_unittest.cc index 40c4aee76..28e4e4b28 100644 --- a/src/protozero/filtering/filter_bytecode_parser_unittest.cc +++ b/src/protozero/filtering/filter_bytecode_parser_unittest.cc @@ -47,6 +47,7 @@ TEST(FilterBytecodeParserTest, ParserSimpleFields) { EXPECT_TRUE(LoadBytecode(&parser, {})); EXPECT_FALSE(parser.Query(0, 0).allowed); + EXPECT_FALSE(parser.Query(0, 0xffffffff).allowed); EXPECT_FALSE(parser.Query(1, 0).allowed); EXPECT_FALSE(parser.Query(0, 1).allowed); EXPECT_FALSE(parser.Query(1, 1).allowed); diff --git a/src/protozero/filtering/message_tokenizer.h b/src/protozero/filtering/message_tokenizer.h new file mode 100644 index 000000000..124b461ab --- /dev/null +++ b/src/protozero/filtering/message_tokenizer.h @@ -0,0 +1,199 @@ +/* + * Copyright (C) 2021 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. + */ + +#ifndef SRC_PROTOZERO_FILTERING_MESSAGE_TOKENIZER_H_ +#define SRC_PROTOZERO_FILTERING_MESSAGE_TOKENIZER_H_ + +#include <stdint.h> + +#include "perfetto/base/compiler.h" +#include "perfetto/base/logging.h" +#include "perfetto/protozero/proto_utils.h" + +namespace protozero { + +// A helper class for schema-less tokenizing of protobuf messages. +// This class takes a stream of proto-encoded bytes, pushed one by one in input +// via Push(octet), and returns a stream of tokens (each Push() call can return +// 0 or 1 token). +// A "token" contains metadata about a field, specifically: its ID, its wire +// type and: +// - For varint and fixed32/64 fields: its payload. +// - For string and bytes fields: the length of its payload. +// In this case the caller is supposed to "eat" those N bytes before calling +// Push() again. +// Note that this class cannot differentiate between a string/bytes field or +// a submessage, because they are encoded in the same way. The caller is +// supposed to know whether a field can be recursed into by just keep calling +// Push() or is a string that should be skipped. +// This is inline to allow the compiler to see through the Push method and +// avoid a function call for each byte. +class MessageTokenizer { + public: + struct Token { + uint32_t field_id; // 0 == not valid. + proto_utils::ProtoWireType type; + + // For kLengthDelimited, |value| represent the length of the payload. + uint64_t value; + + inline bool valid() const { return field_id != 0; } + bool operator==(const Token& o) const { + return field_id == o.field_id && type == o.type && value == o.value; + } + }; + + // Pushes a byte in input and returns a token, only when getting to the last + // byte of each field. Specifically: + // - For varint and fixed32 fields, the Token is returned after the last byte + // of the numeric payload is pushed. + // - For length-delimited fields, this returns after the last byte of the + // length is pushed (i.e. right before the payload starts). The caller is + // expected to either skip the next |value| bytes (in the case of a string + // or bytes fields) or keep calling Push, in the case of a submessage. + inline Token Push(uint8_t octet) { + using protozero::proto_utils::ProtoWireType; + + // Parsing a fixed32/64 field is the only case where we don't have to do + // any varint decoding. This is why this block is before the remaining + // switch statement below (all the rest is a varint). + if (PERFETTO_UNLIKELY(state_ == kFixedIntValue)) { + PERFETTO_DCHECK(fixed_int_bits_ == 32 || fixed_int_bits_ == 64); + fixed_int_value_ |= static_cast<uint64_t>(octet) << fixed_int_shift_; + fixed_int_shift_ += 8; + if (fixed_int_shift_ < fixed_int_bits_) + return Token{}; // Intermediate byte of a fixed32/64. + auto wire_type = fixed_int_bits_ == 32 ? ProtoWireType::kFixed32 + : ProtoWireType::kFixed64; + uint64_t fixed_int_value = fixed_int_value_; + fixed_int_value_ = fixed_int_shift_ = fixed_int_bits_ = 0; + state_ = kFieldPreamble; + return Token{field_id_, wire_type, fixed_int_value}; + } + + // At this point either we are: (i) parsing a field preamble; (ii) parsing a + // varint field paylod; (iii) parsing the length of a length-delimited + // field. In all cases, we need to decode a varint before proceeding. + varint_ |= static_cast<uint64_t>(octet & 0x7F) << varint_shift_; + if (octet & 0x80) { + varint_shift_ += 7; + if (PERFETTO_UNLIKELY(varint_shift_ >= 64)) { + varint_shift_ = 0; + state_ = kInvalidVarInt; + } + return Token{}; // Still parsing a varint. + } + + uint64_t varint = varint_; + varint_ = 0; + varint_shift_ = 0; + + switch (state_) { + case kFieldPreamble: { + auto field_type = static_cast<uint32_t>(varint & 7u); // 7 = 0..0111 + field_id_ = static_cast<uint32_t>(varint >> 3); + + // The field type is legit, now check it's well formed and within + // boundaries. + if (field_type == static_cast<uint32_t>(ProtoWireType::kVarInt)) { + state_ = kVarIntValue; + } else if (field_type == + static_cast<uint32_t>(ProtoWireType::kFixed32) || + field_type == + static_cast<uint32_t>(ProtoWireType::kFixed64)) { + state_ = kFixedIntValue; + fixed_int_shift_ = 0; + fixed_int_value_ = 0; + fixed_int_bits_ = + field_type == static_cast<uint32_t>(ProtoWireType::kFixed32) ? 32 + : 64; + } else if (field_type == + static_cast<uint32_t>(ProtoWireType::kLengthDelimited)) { + state_ = kLenDelimited; + } else { + state_ = kInvalidFieldType; + } + return Token{}; + } + + case kVarIntValue: { + // Return the varint field payload and go back to the next field. + state_ = kFieldPreamble; + return Token{field_id_, ProtoWireType::kVarInt, varint}; + } + + case kLenDelimited: { + const auto payload_len = varint; + if (payload_len > protozero::proto_utils::kMaxMessageLength) { + state_ = kMessageTooBig; + return Token{}; + } + state_ = kFieldPreamble; + // At this point the caller is expected to consume the next + // |payload_len| bytes. + return Token{field_id_, ProtoWireType::kLengthDelimited, payload_len}; + } + + case kFixedIntValue: + // Unreacheable because of the if before the switch. + PERFETTO_DCHECK(false); + break; + + // Unrecoverable error states. + case kInvalidFieldType: + case kMessageTooBig: + case kInvalidVarInt: + break; + } // switch(state_) + + return Token{}; // Keep GCC happy. + } + + // Returns true if the tokenizer FSM has reached quiescence (i.e. if we are + // NOT in the middle of parsing a field). + bool idle() const { + return state_ == kFieldPreamble && varint_shift_ == 0 && + fixed_int_shift_ == 0; + } + + // Only for reporting parser errors in the trace. + uint32_t state() const { return static_cast<uint32_t>(state_); } + + private: + enum State { + kFieldPreamble = 0, // Parsing the varint for the field preamble. + kVarIntValue = 1, // Parsing the payload of a varint field. + kFixedIntValue = 2, // Parsing the payload of a fixed32/64 field. + kLenDelimited = 3, // Parsing the length of a length-delimited field. + + // Unrecoverable error states: + kInvalidFieldType = 4, // Encountered an invalid field type. + kMessageTooBig = 5, // Size of the length delimited message was too big. + kInvalidVarInt = 6, // Varint larger than 64 bits. + }; + + State state_ = kFieldPreamble; + uint32_t field_id_ = 0; + uint64_t varint_ = 0; + uint32_t varint_shift_ = 0; + uint32_t fixed_int_shift_ = 0; + uint32_t fixed_int_bits_ = 0; + uint64_t fixed_int_value_ = 0; +}; + +} // namespace protozero + +#endif // SRC_PROTOZERO_FILTERING_MESSAGE_TOKENIZER_H_ diff --git a/src/protozero/filtering/message_tokenizer_unittest.cc b/src/protozero/filtering/message_tokenizer_unittest.cc new file mode 100644 index 000000000..666c4cf36 --- /dev/null +++ b/src/protozero/filtering/message_tokenizer_unittest.cc @@ -0,0 +1,179 @@ +/* + * Copyright (C) 2021 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 "test/gtest_and_gmock.h" + +#include "perfetto/protozero/message.h" +#include "perfetto/protozero/scattered_heap_buffer.h" +#include "src/protozero/filtering/message_tokenizer.h" + +namespace protozero { + +using proto_utils::ProtoWireType; +using ::testing::ElementsAre; +using Token = MessageTokenizer::Token; + +// For ASSERT_THAT(ElementsAre(...)) +inline std::ostream& operator<<(std::ostream& stream, const Token& t) { + stream << "{" << t.field_id << ", "; + switch (t.type) { + case ProtoWireType::kVarInt: + stream << "varint, "; + break; + case ProtoWireType::kFixed32: + stream << "fixed32, "; + break; + case ProtoWireType::kFixed64: + stream << "fixed64, "; + break; + case ProtoWireType::kLengthDelimited: + stream << "lendelim, "; + break; + default: + stream << "???, "; + break; + } + stream << t.value << "}"; + return stream; +} + +namespace { + +TEST(MessageTokenizerTest, FlatMessage) { + HeapBuffered<Message> msg; + msg->AppendVarInt(/*field_id*/ 1, 42u); + msg->AppendVarInt(/*field_id*/ 1, 1000u); + msg->AppendVarInt(/*field_id*/ 2, 1000000000ull); + msg->AppendVarInt(/*field_id*/ 3, 0xFF001234DEADBEEFull); + msg->AppendString(/*field_id*/ 4, "foo"); + msg->AppendFixed(/*field_id*/ 5, 0xFFAAFFFFu); + msg->AppendString(/*field_id*/ 4, "foobar"); + msg->AppendFixed(/*field_id*/ 6, uint64_t(1ull << 63)); + msg->AppendVarInt(/*field_id*/ 1000, 1001ull); + msg->AppendVarInt(/*field_id*/ 1000000, 1000001ull); + msg->AppendVarInt(/*field_id*/ 1 << 28, uint64_t(1ull << 63)); + + // Treat all len-delimited fields as strings/bytes and just eat their payload. + MessageTokenizer tokenizer; + std::vector<Token> tokens; + size_t eat_bytes = 0; + for (uint8_t octet : msg.SerializeAsArray()) { + if (eat_bytes > 0) { + --eat_bytes; + continue; + } + auto token = tokenizer.Push(octet); + if (token.valid()) + tokens.emplace_back(token); + if (token.type == ProtoWireType::kLengthDelimited) { + ASSERT_EQ(eat_bytes, 0u); + eat_bytes = static_cast<size_t>(token.value); + } + } + EXPECT_TRUE(tokenizer.idle()); + EXPECT_THAT( + tokens, + ElementsAre( + Token{1, ProtoWireType::kVarInt, 42u}, + Token{1, ProtoWireType::kVarInt, 1000u}, + Token{2, ProtoWireType::kVarInt, 1000000000ull}, + Token{3, ProtoWireType::kVarInt, 0xFF001234DEADBEEFull}, + Token{4, ProtoWireType::kLengthDelimited, 3}, + Token{5, ProtoWireType::kFixed32, 0xFFAAFFFFu}, + Token{4, ProtoWireType::kLengthDelimited, 6}, + Token{6, ProtoWireType::kFixed64, uint64_t(1ull << 63)}, + Token{1000, ProtoWireType::kVarInt, 1001ull}, + Token{1000000, ProtoWireType::kVarInt, 1000001ull}, + Token{1 << 28, ProtoWireType::kVarInt, uint64_t(1ull << 63)})); +} + +TEST(MessageTokenizerTest, NestedMessage) { + HeapBuffered<Message> msg; + msg->AppendVarInt(/*field_id*/ 1, 101u); + { + auto* nested = msg->BeginNestedMessage<Message>(2); + nested->AppendVarInt(/*field_id*/ 3, 103u); + nested->AppendFixed(/*field_id*/ 4, 104u); + { + auto* nested2 = nested->BeginNestedMessage<Message>(5); + nested2->AppendVarInt(/*field_id*/ 6, 106u); + nested2->AppendFixed(/*field_id*/ 7, 107u); + nested2->Finalize(); + } + nested->AppendFixed(/*field_id*/ 8, 0x42420000u); + nested->Finalize(); + } + msg->AppendFixed(/*field_id*/ 9, uint64_t(1ull << 63)); + + // Tokenize the message. This treat all len delimited fields as submessage + // and test the recursion logic. + MessageTokenizer tokenizer; + std::vector<Token> tokens; + for (uint8_t octet : msg.SerializeAsArray()) { + auto token = tokenizer.Push(octet); + if (token.valid()) + tokens.emplace_back(token); + } + EXPECT_TRUE(tokenizer.idle()); + EXPECT_THAT( + tokens, + ElementsAre(Token{1, ProtoWireType::kVarInt, 101u}, + Token{2, ProtoWireType::kLengthDelimited, 24u}, + Token{3, ProtoWireType::kVarInt, 103u}, + Token{4, ProtoWireType::kFixed32, 104u}, + Token{5, ProtoWireType::kLengthDelimited, 7}, + Token{6, ProtoWireType::kVarInt, 106u}, + Token{7, ProtoWireType::kFixed32, 107u}, + Token{8, ProtoWireType::kFixed32, 0x42420000u}, + Token{9, ProtoWireType::kFixed64, uint64_t(1ull << 63)})); +} + +TEST(MessageTokenizerTest, InvlidCases) { + { + // A very large varint. + MessageTokenizer tokenizer; + EXPECT_FALSE(tokenizer.Push(0x08).valid()); + for (int i = 0; i < 14; ++i) + EXPECT_FALSE(tokenizer.Push(0xff).valid()); + EXPECT_FALSE(tokenizer.Push(0x0).valid()); + EXPECT_FALSE(tokenizer.idle()); + EXPECT_EQ(tokenizer.state(), 6u); + } + { + // A very large string. + MessageTokenizer tokenizer; + EXPECT_FALSE(tokenizer.Push(0x0A).valid()); + EXPECT_FALSE(tokenizer.Push(0xFF).valid()); + EXPECT_FALSE(tokenizer.Push(0xFF).valid()); + EXPECT_FALSE(tokenizer.Push(0xFF).valid()); + EXPECT_FALSE(tokenizer.Push(0xFF).valid()); + EXPECT_FALSE(tokenizer.Push(0x20).valid()); + EXPECT_FALSE(tokenizer.idle()); + EXPECT_EQ(tokenizer.state(), 5u); + } + { + // A field of unknown type (wire type = 0x3). + MessageTokenizer tokenizer; + EXPECT_FALSE(tokenizer.Push(0x0B).valid()); + EXPECT_FALSE(tokenizer.Push(0).valid()); + EXPECT_FALSE(tokenizer.Push(0).valid()); + EXPECT_FALSE(tokenizer.idle()); + EXPECT_EQ(tokenizer.state(), 4u); + } +} + +} // namespace +} // namespace protozero diff --git a/src/trace_processor/importers/common/clock_tracker.cc b/src/trace_processor/importers/common/clock_tracker.cc index f59fbfcd4..75518a263 100644 --- a/src/trace_processor/importers/common/clock_tracker.cc +++ b/src/trace_processor/importers/common/clock_tracker.cc @@ -41,7 +41,7 @@ ClockTracker::ClockTracker(TraceProcessorContext* ctx) ClockTracker::~ClockTracker() = default; -void ClockTracker::AddSnapshot(const std::vector<ClockValue>& clocks) { +uint32_t ClockTracker::AddSnapshot(const std::vector<ClockValue>& clocks) { const auto snapshot_id = cur_snapshot_id_++; // Clear the cache @@ -65,7 +65,7 @@ void ClockTracker::AddSnapshot(const std::vector<ClockValue>& clocks) { "supported for sequence-scoped clocks.", clock_id); context_->storage->IncrementStats(stats::invalid_clock_snapshots); - return; + return snapshot_id; } domain.unit_multiplier_ns = clock.unit_multiplier_ns; domain.is_incremental = clock.is_incremental; @@ -79,7 +79,7 @@ void ClockTracker::AddSnapshot(const std::vector<ClockValue>& clocks) { clock_id, clock.unit_multiplier_ns, clock.is_incremental, domain.unit_multiplier_ns, domain.is_incremental); context_->storage->IncrementStats(stats::invalid_clock_snapshots); - return; + return snapshot_id; } const int64_t timestamp_ns = clock.absolute_timestamp * domain.unit_multiplier_ns; @@ -92,7 +92,7 @@ void ClockTracker::AddSnapshot(const std::vector<ClockValue>& clocks) { " at snapshot %" PRIu32 ".", clock_id, snapshot_id); context_->storage->IncrementStats(stats::invalid_clock_snapshots); - return; + return snapshot_id; } // Clock ids in the range [64, 128) are sequence-scoped and must be @@ -116,7 +116,7 @@ void ClockTracker::AddSnapshot(const std::vector<ClockValue>& clocks) { clock_id, snapshot_id, timestamp_ns, vect.timestamps_ns.back()); context_->storage->IncrementStats(stats::invalid_clock_snapshots); - return; + return snapshot_id; } PERFETTO_DLOG("Detected non-monotonic clock with ID %" PRIu64, clock_id); @@ -159,6 +159,7 @@ void ClockTracker::AddSnapshot(const std::vector<ClockValue>& clocks) { graph_.emplace(it2->clock_id, it1->clock_id, snapshot_hash); } } + return snapshot_id; } // Finds the shortest clock resolution path in the graph that allows to diff --git a/src/trace_processor/importers/common/clock_tracker.h b/src/trace_processor/importers/common/clock_tracker.h index 80b2a4e9d..16b9d79ff 100644 --- a/src/trace_processor/importers/common/clock_tracker.h +++ b/src/trace_processor/importers/common/clock_tracker.h @@ -154,7 +154,8 @@ class ClockTracker { // Appends a new snapshot for the given clock domains. // This is typically called by the code that reads the ClockSnapshot packet. - void AddSnapshot(const std::vector<ClockValue>&); + // Returns the internal snapshot id of this set of clocks. + uint32_t AddSnapshot(const std::vector<ClockValue>&); // Converts a timestamp between two clock domains. Tries to use the cache // first (only for single-path resolutions), then falls back on path finding diff --git a/src/trace_processor/importers/proto/proto_trace_parser.cc b/src/trace_processor/importers/proto/proto_trace_parser.cc index bbe895c79..26383f2c7 100644 --- a/src/trace_processor/importers/proto/proto_trace_parser.cc +++ b/src/trace_processor/importers/proto/proto_trace_parser.cc @@ -243,7 +243,7 @@ void ProtoTraceParser::ParseTraceStats(ConstBytes blob) { } void ProtoTraceParser::ParseProfilePacket( - int64_t, + int64_t ts, PacketSequenceStateGeneration* sequence_state, uint32_t seq_id, ConstBytes blob) { @@ -297,6 +297,8 @@ void ProtoTraceParser::ParseProfilePacket( int64_t timestamp = *maybe_timestamp; int pid = static_cast<int>(entry.pid()); + context_->storage->SetIndexedStats(stats::heapprofd_last_profile_timestamp, + pid, ts); if (entry.disconnected()) context_->storage->IncrementIndexedStats( diff --git a/src/trace_processor/importers/proto/proto_trace_reader.cc b/src/trace_processor/importers/proto/proto_trace_reader.cc index 863d5bd4a..ee03db396 100644 --- a/src/trace_processor/importers/proto/proto_trace_reader.cc +++ b/src/trace_processor/importers/proto/proto_trace_reader.cc @@ -378,10 +378,61 @@ util::Status ProtoTraceReader::ParseClockSnapshot(ConstBytes blob, clocks.emplace_back(clock_id, clk.timestamp(), unit_multiplier_ns, clk.is_incremental()); } - context_->clock_tracker->AddSnapshot(clocks); + + uint32_t snapshot_id = context_->clock_tracker->AddSnapshot(clocks); + + // Add the all the clock values to the clock snapshot table. + base::Optional<int64_t> trace_ts_for_check; + for (const auto& clock : clocks) { + // If the clock is incremental, we need to use 0 to map correctly to + // |absolute_timestamp|. + int64_t ts_to_convert = clock.is_incremental ? 0 : clock.absolute_timestamp; + base::Optional<int64_t> opt_trace_ts = + context_->clock_tracker->ToTraceTime(clock.clock_id, ts_to_convert); + if (!opt_trace_ts) { + // This can happen if |AddSnapshot| failed to resolve this clock. Just + // ignore this and move on. + continue; + } + + // Double check that all the clocks in this snapshot resolve to the same + // trace timestamp value. + PERFETTO_DCHECK(!trace_ts_for_check || opt_trace_ts == trace_ts_for_check); + trace_ts_for_check = *opt_trace_ts; + + tables::ClockSnapshotTable::Row row; + row.ts = *opt_trace_ts; + row.clock_id = static_cast<int64_t>(clock.clock_id); + row.clock_value = clock.absolute_timestamp; + row.clock_name = GetBuiltinClockNameOrNull(clock.clock_id); + row.snapshot_id = snapshot_id; + + auto* snapshot_table = context_->storage->mutable_clock_snapshot_table(); + snapshot_table->Insert(row); + } return util::OkStatus(); } +base::Optional<StringId> ProtoTraceReader::GetBuiltinClockNameOrNull( + uint64_t clock_id) { + switch (clock_id) { + case protos::pbzero::ClockSnapshot::Clock::REALTIME: + return context_->storage->InternString("REALTIME"); + case protos::pbzero::ClockSnapshot::Clock::REALTIME_COARSE: + return context_->storage->InternString("REALTIME_COARSE"); + case protos::pbzero::ClockSnapshot::Clock::MONOTONIC: + return context_->storage->InternString("MONOTONIC"); + case protos::pbzero::ClockSnapshot::Clock::MONOTONIC_COARSE: + return context_->storage->InternString("MONOTONIC_COARSE"); + case protos::pbzero::ClockSnapshot::Clock::MONOTONIC_RAW: + return context_->storage->InternString("MONOTONIC_RAW"); + case protos::pbzero::ClockSnapshot::Clock::BOOTTIME: + return context_->storage->InternString("BOOTTIME"); + default: + return base::nullopt; + } +} + util::Status ProtoTraceReader::ParseServiceEvent(int64_t ts, ConstBytes blob) { protos::pbzero::TracingServiceEvent::Decoder tse(blob); if (tse.tracing_started()) { diff --git a/src/trace_processor/importers/proto/proto_trace_reader.h b/src/trace_processor/importers/proto/proto_trace_reader.h index b2f4069f4..1adb84151 100644 --- a/src/trace_processor/importers/proto/proto_trace_reader.h +++ b/src/trace_processor/importers/proto/proto_trace_reader.h @@ -75,6 +75,8 @@ class ProtoTraceReader : public ChunkedTraceReader { TraceBlobView interned_data); void ParseTraceConfig(ConstBytes); + base::Optional<StringId> GetBuiltinClockNameOrNull(uint64_t clock_id); + PacketSequenceState* GetIncrementalStateForPacketSequence( uint32_t sequence_id) { if (!incremental_state) diff --git a/src/trace_processor/metrics/android/android_startup.sql b/src/trace_processor/metrics/android/android_startup.sql index 0c6d42961..b97a2abc3 100644 --- a/src/trace_processor/metrics/android/android_startup.sql +++ b/src/trace_processor/metrics/android/android_startup.sql @@ -143,7 +143,8 @@ WHERE slice.name IN ( 'activityRestart', 'activityResume', 'inflate', - 'ResourcesManager#getResources') + 'ResourcesManager#getResources', + 'binder transaction') OR slice.name LIKE 'performResume:%' OR slice.name LIKE 'performCreate:%' OR slice.name LIKE 'location=% status=% filter=% reason=%' @@ -264,6 +265,16 @@ WHERE AND thread_name = 'Jit thread pool' GROUP BY launch_id; +DROP TABLE IF EXISTS long_binder_transactions; +CREATE TABLE long_binder_transactions AS +SELECT + launch_id, slice_dur, thread_name +FROM + main_process_slice_unaggregated +WHERE + slice_name = 'binder transaction' + AND slice_dur >= 1e8; + DROP VIEW IF EXISTS startup_view; CREATE VIEW startup_view AS SELECT @@ -293,6 +304,17 @@ SELECT FROM activity_names_materialized s WHERE s.launch_id = launches.id ), + 'long_binder_transactions', ( + SELECT RepeatedField(AndroidStartupMetric_BinderTransaction( + 'duration', AndroidStartupMetric_Slice( + 'dur_ns', lbt.slice_dur, + 'dur_ms', lbt.slice_dur / 1e6 + ), + 'thread', lbt.thread_name + )) + FROM long_binder_transactions lbt + WHERE lbt.launch_id = launches.id + ), 'zygote_new_process', EXISTS(SELECT TRUE FROM zygote_forks_by_id WHERE id = launches.id), 'activity_hosting_process_count', ( SELECT COUNT(1) FROM launch_processes p diff --git a/src/trace_processor/metrics/android/hsc_startups.sql b/src/trace_processor/metrics/android/hsc_startups.sql index b07f5450f..5c0a6181e 100644 --- a/src/trace_processor/metrics/android/hsc_startups.sql +++ b/src/trace_processor/metrics/android/hsc_startups.sql @@ -105,7 +105,7 @@ SELECT frame_times.ts_end - launches.ts as ts_total FROM frame_times INNER JOIN launches on launches.package LIKE '%' || frame_times.name || '%' -WHERE frame_times.ts > (SELECT ts + dur FROM animators WHERE animator_name="animator:translationZ" AND process_name LIKE "%id.deskclock" ORDER BY ts DESC LIMIT 1) AND frame_times.name LIKE "%id.deskclock" AND frame_times.launch_id = launches.id +WHERE frame_times.ts > (SELECT ts + dur FROM animators WHERE animator_name="animator:translationZ" AND process_name LIKE "%id.deskclock" ORDER BY (ts+dur) DESC LIMIT 1) AND frame_times.name LIKE "%id.deskclock" AND frame_times.launch_id = launches.id ORDER BY ts_total LIMIT 1; -- Contacts @@ -158,7 +158,7 @@ SELECT frame_times.ts_end - launches.ts as ts_total FROM frame_times INNER JOIN launches on launches.package LIKE '%' || frame_times.name || '%' -WHERE frame_times.ts > (SELECT ts + dur FROM animators WHERE animator_name="animator:elevation" AND process_name LIKE "%android.gm" ORDER BY ts DESC LIMIT 1) AND frame_times.name LIKE "%android.gm" AND frame_times.launch_id = launches.id +WHERE frame_times.ts > (SELECT ts + dur FROM animators WHERE animator_name="animator:elevation" AND process_name LIKE "%android.gm" ORDER BY (ts+dur) DESC LIMIT 1) AND frame_times.name LIKE "%android.gm" AND frame_times.launch_id = launches.id ORDER BY ts_total LIMIT 1; -- Instagram diff --git a/src/trace_processor/python/perfetto/trace_processor/metrics.descriptor b/src/trace_processor/python/perfetto/trace_processor/metrics.descriptor index 2670372e1..b5e2561d5 100644 --- a/src/trace_processor/python/perfetto/trace_processor/metrics.descriptor +++ b/src/trace_processor/python/perfetto/trace_processor/metrics.descriptor @@ -357,8 +357,8 @@ PowerRails name ( RnameN energy_data (2-.perfetto.protos.AndroidPowerRails.EnergyDataR energyData -ä -4protos/perfetto/metrics/android/startup_metric.protoperfetto.protos6protos/perfetto/metrics/android/process_metadata.proto"â +Í" +4protos/perfetto/metrics/android/startup_metric.protoperfetto.protos6protos/perfetto/metrics/android/process_metadata.proto"Ë! AndroidStartupMetricG startup (2-.perfetto.protos.AndroidStartupMetric.StartupRstartupà TaskStateBreakdown$ @@ -409,7 +409,10 @@ HscMetricsN Activity name ( Rname method ( Rmethod& -ts_method_start (R
tsMethodStartJ¯ +ts_method_start (R
tsMethodStartJt +BinderTransactionG +duration (2+.perfetto.protos.AndroidStartupMetric.SliceRduration +thread ( Rthread¯ OptimizationStatus odex_status ( R odexStatus- @@ -419,7 +422,7 @@ odexStatus- EventTimestamps' intent_received (RintentReceived first_frame (R -firstFrameÀ +firstFrame³ Startup startup_id (
R startupId! @@ -427,7 +430,8 @@ startup_id (
R startupId! process_name ( RprocessNameN activities (2..perfetto.protos.AndroidStartupMetric.ActivityR -activities, +activitiesq +long_binder_transactions (27.perfetto.protos.AndroidStartupMetric.BinderTransactionRlongBinderTransactions, zygote_new_process (RzygoteNewProcessC activity_hosting_process_count (
RactivityHostingProcessCount` event_timestamps
(25.perfetto.protos.AndroidStartupMetric.EventTimestampsReventTimestampsX @@ -472,11 +476,12 @@ jank_cause ( R jankCause threadName uid (Ruid( uid_package_name ( RuidPackageName -é -Aprotos/perfetto/metrics/android/thread_time_in_state_metric.protoperfetto.protos6protos/perfetto/metrics/android/process_metadata.proto"Ú +” +Aprotos/perfetto/metrics/android/thread_time_in_state_metric.protoperfetto.protos6protos/perfetto/metrics/android/process_metadata.proto"… AndroidThreadTimeInStateMetricU - processes (27.perfetto.protos.AndroidThreadTimeInStateMetric.ProcessR processes• -MetricsByCoreType + processes (27.perfetto.protos.AndroidThreadTimeInStateMetric.ProcessR processesÀ +MetricsByCoreType) +time_in_state_cpu (RtimeInStateCpu core_type ( RcoreType runtime_ms (R runtimeMs diff --git a/src/trace_processor/storage/stats.h b/src/trace_processor/storage/stats.h index c66923a3f..bc44fef4c 100644 --- a/src/trace_processor/storage/stats.h +++ b/src/trace_processor/storage/stats.h @@ -157,6 +157,8 @@ namespace stats { "Number of samples unwound."), \ F(heapprofd_client_spinlock_blocked, kIndexed, kInfo, kTrace, \ "Time (us) the heapprofd client was blocked on the spinlock."), \ + F(heapprofd_last_profile_timestamp, kIndexed, kInfo, kTrace, \ + "The timestamp (in trace time) for the last dump for a process"), \ F(metatrace_overruns, kSingle, kError, kTrace, ""), \ F(packages_list_has_parse_errors, kSingle, kError, kTrace, ""), \ F(packages_list_has_read_errors, kSingle, kError, kTrace, ""), \ diff --git a/src/trace_processor/storage/trace_storage.h b/src/trace_processor/storage/trace_storage.h index 698aa7cd1..e2af2ce75 100644 --- a/src/trace_processor/storage/trace_storage.h +++ b/src/trace_processor/storage/trace_storage.h @@ -442,6 +442,13 @@ class TraceStorage { } tables::MetadataTable* mutable_metadata_table() { return &metadata_table_; } + const tables::ClockSnapshotTable& clock_snapshot_table() const { + return clock_snapshot_table_; + } + tables::ClockSnapshotTable* mutable_clock_snapshot_table() { + return &clock_snapshot_table_; + } + const tables::ArgTable& arg_table() const { return arg_table_; } tables::ArgTable* mutable_arg_table() { return &arg_table_; } @@ -719,6 +726,9 @@ class TraceStorage { // * descriptions of android packages tables::MetadataTable metadata_table_{&string_pool_, nullptr}; + // Contains data from all the clock snapshots in the trace. + tables::ClockSnapshotTable clock_snapshot_table_{&string_pool_, nullptr}; + // Metadata for tracks. tables::TrackTable track_table_{&string_pool_, nullptr}; tables::GpuTrackTable gpu_track_table_{&string_pool_, &track_table_}; diff --git a/src/trace_processor/tables/metadata_tables.h b/src/trace_processor/tables/metadata_tables.h index fa3136b46..3f1bb9074 100644 --- a/src/trace_processor/tables/metadata_tables.h +++ b/src/trace_processor/tables/metadata_tables.h @@ -113,6 +113,28 @@ PERFETTO_TP_TABLE(PERFETTO_TP_CPU_TABLE_DEF); PERFETTO_TP_TABLE(PERFETTO_TP_CPU_FREQ_TABLE_DEF); +// Contains all the mapping between clock snapshots and trace time. +// +// NOTE: this table is not sorted by timestamp; this is why we omit the +// sorted flag on the ts column. +// +// @param ts timestamp of the snapshot in trace time. +// @param clock_id id of the clock (corresponds to the id in the trace). +// @param clock_name the name of the clock for builtin clocks or null +// otherwise. +// @param clock_value timestamp of the snapshot in clock time. +// @param snapshot_id the index of this snapshot (only useful for debugging) +#define PERFETTO_TP_CLOCK_SNAPSHOT_TABLE_DEF(NAME, PARENT, C) \ + NAME(ClockSnapshotTable, "clock_snapshot") \ + PERFETTO_TP_ROOT_TABLE(PARENT, C) \ + C(int64_t, ts) \ + C(int64_t, clock_id) \ + C(base::Optional<StringPool::Id>, clock_name) \ + C(int64_t, clock_value) \ + C(uint32_t, snapshot_id) + +PERFETTO_TP_TABLE(PERFETTO_TP_CLOCK_SNAPSHOT_TABLE_DEF); + } // namespace tables } // namespace trace_processor } // namespace perfetto diff --git a/src/trace_processor/tables/table_destructors.cc b/src/trace_processor/tables/table_destructors.cc index d57b71b68..34206b9b3 100644 --- a/src/trace_processor/tables/table_destructors.cc +++ b/src/trace_processor/tables/table_destructors.cc @@ -45,6 +45,7 @@ CpuTable::~CpuTable() = default; CpuFreqTable::~CpuFreqTable() = default; ThreadTable::~ThreadTable() = default; ProcessTable::~ProcessTable() = default; +ClockSnapshotTable::~ClockSnapshotTable() = default; // profiler_tables.h StackProfileMappingTable::~StackProfileMappingTable() = default; diff --git a/src/trace_processor/trace_processor_impl.cc b/src/trace_processor/trace_processor_impl.cc index 8893144e6..0ca05ead6 100644 --- a/src/trace_processor/trace_processor_impl.cc +++ b/src/trace_processor/trace_processor_impl.cc @@ -825,6 +825,7 @@ TraceProcessorImpl::TraceProcessorImpl(const Config& cfg) RegisterDbTable(storage->metadata_table()); RegisterDbTable(storage->cpu_table()); RegisterDbTable(storage->cpu_freq_table()); + RegisterDbTable(storage->clock_snapshot_table()); RegisterDbTable(storage->memory_snapshot_table()); RegisterDbTable(storage->process_memory_snapshot_table()); diff --git a/test/trace_processor/startup/android_startup_attribution.out b/test/trace_processor/startup/android_startup_attribution.out index 4673d7122..5046ed44b 100644 --- a/test/trace_processor/startup/android_startup_attribution.out +++ b/test/trace_processor/startup/android_startup_attribution.out @@ -5,7 +5,7 @@ android_startup { process_name: "com.some.app" zygote_new_process: false to_first_frame { - dur_ns: 9900 + dur_ns: 999999900 main_thread_by_task_state { running_dur_ns: 0 runnable_dur_ns: 0 @@ -17,7 +17,7 @@ android_startup { dur_ns: 2 dur_ms: 2e-06 } - dur_ms: 0.0099 + dur_ms: 999.9999 time_dex_open { dur_ns: 20 dur_ms: 2e-05 @@ -48,7 +48,21 @@ android_startup { } event_timestamps { intent_received: 100 - first_frame: 10000 + first_frame: 1000000000 + } + long_binder_transactions { + duration { + dur_ns: 100000000 + dur_ms: 100 + } + thread: "Binder" + } + long_binder_transactions { + duration { + dur_ns: 200000000 + dur_ms: 200 + } + thread: "fonts" } } } diff --git a/test/trace_processor/startup/android_startup_attribution.py b/test/trace_processor/startup/android_startup_attribution.py index 699dfa8ba..61d9ebc5f 100644 --- a/test/trace_processor/startup/android_startup_attribution.py +++ b/test/trace_processor/startup/android_startup_attribution.py @@ -23,10 +23,12 @@ SECOND_APP_TID = 3 JIT_TID = 4 GC_TID = 5 GC2_TID = 6 +BINDER_TID = 7 +FONTS_TID = 8 SYSTEM_SERVER_PID = 2 SYSTEM_SERVER_TID = 2 LAUNCH_START_TS = 100 -LAUNCH_END_TS = 10000 +LAUNCH_END_TS = 10**9 trace = synth_common.create_trace() trace.add_packet() @@ -43,6 +45,8 @@ trace.add_thread( tid=GC_TID, tgid=APP_PID, cmdline='HeapTaskDaemon', name='HeapTaskDaemon') trace.add_thread( tid=GC2_TID, tgid=APP_PID, cmdline='HeapTaskDaemon', name='HeapTaskDaemon') +trace.add_thread(tid=BINDER_TID, tgid=APP_PID, cmdline='Binder', name='Binder') +trace.add_thread(tid=FONTS_TID, tgid=APP_PID, cmdline='fonts', name='fonts') trace.add_ftrace_packet(cpu=0) # Start intent. @@ -145,6 +149,20 @@ trace.add_sched(ts=350, prev_pid=GC2_TID, next_pid=GC_TID) # Finish running for GC. trace.add_sched(ts=360, prev_pid=GC_TID, next_pid=0) +# Long binder transactions. +trace.add_atrace_begin( + ts=10**8, pid=APP_PID, tid=BINDER_TID, buf='binder transaction') +trace.add_atrace_end(ts=2 * (10**8), pid=APP_PID, tid=BINDER_TID) + +trace.add_atrace_begin( + ts=3 * (10**8), pid=APP_PID, tid=FONTS_TID, buf='binder transaction') +trace.add_atrace_end(ts=5 * (10**8), pid=APP_PID, tid=FONTS_TID) + +# A short binder transaction. +trace.add_atrace_begin( + ts=10**7, pid=APP_PID, tid=BINDER_TID, buf='binder transaction') +trace.add_atrace_end(ts=6 * (10**7), pid=APP_PID, tid=BINDER_TID) + # Intent successful. trace.add_atrace_begin( ts=LAUNCH_END_TS + 1, |